2/16 17:05:34 DEBUG: [1][ndmp_door_init:106]:ndmp_door_init: Door server successfully started 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_enable_barcode:884]:Barcode capability on library 1 enabled. 2/16 17:05:34 DEBUG: [1][add_lib:289]:lib 1 sid 0 lun 0 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_init:556]:nlibs 1 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][add_drv:439]:vlib(2, 1) sid 1 lun 0 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][add_drv:439]:vlib(2, 2) sid 0 lun 0 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_ioctl:1168]:tlm_ioctl fd 10 cmd 1225 2/16 17:05:34 DEBUG: [1][tlm_init:564]:vlibs 2 2/16 17:05:34 DEBUG: [1][inaccbl_drv_warn:507]:Warning: The following drives are not accessible: 2/16 17:05:34 DEBUG: [1][inaccbl_drv_warn:513]:/dev/rmt/1n 2/16 17:05:34 DEBUG: [1][inaccbl_drv_warn:513]:/dev/scsi/changer/c2t0d0 2/16 17:06:03 DEBUG: [4][ndmp_run:306]:connection fd: 11 2/16 17:06:03 DEBUG: [5][ndmp_send_request:458]:handler->mh_xdr_reply == 0 2/16 17:06:03 DEBUG: [5][connection_handler:866]:connection_fd: 11 2/16 17:06:03 DEBUG: [5][hardlink_q_init:66]:qhead = 8167cc8 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1172]:reply_expected: FALSE 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1252]:received request: 0x900 2/16 17:06:03 DEBUG: [5][ndmpd_connect_open_v2:170]:set ver to: 4 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1280]:no more messages in stream buffer 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1172]:reply_expected: FALSE 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1252]:received request: 0x103 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1280]:no more messages in stream buffer 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1172]:reply_expected: FALSE 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1252]:received request: 0x901 2/16 17:06:03 DEBUG: [5][ndmpd_connect_client_auth_v3:449]:auth_type MD5 2/16 17:06:03 DEBUG: [5][ndmpd_connect_auth_md5:1248]:Authorization granted. 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1280]:no more messages in stream buffer 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1172]:reply_expected: FALSE 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1252]:received request: 0x40a 2/16 17:06:03 DEBUG: [5][ndmp_connect_sock_v3:1932]:addr 154.2.168.192:43410 2/16 17:06:03 DEBUG: [5][ndmp_connect_sock_v3:1951]:sock 13 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1280]:no more messages in stream buffer 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1172]:reply_expected: FALSE 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1252]:received request: 0x402 2/16 17:06:03 DEBUG: [5][ndmp_buffer_get_size:1005]:Local operation: 64512 2/16 17:06:03 DEBUG: [5][ndmp_buffer_get_size:1010]:xfer_size: 64512 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(FILESYSTEM): "/fridge/testsnap@monthly03" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(HIST): "n" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(LEVEL): "0" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(TYPE): "zfs" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(UPDATE): "y" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(USER): "root" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(ZFS_BACKUP_SIZE): "2152710680" 2/16 17:06:03 DEBUG: [5][ndmpd_save_env:526]:env(PREFIX): "/fridge/testsnap@monthly03" 2/16 17:06:03 DEBUG: [5][ndmpd_save_nlist_v3:749]:orig "" 2/16 17:06:03 DEBUG: [5][ndmpd_save_nlist_v3:750]:dest "/fridge/restore162" 2/16 17:06:03 DEBUG: [5][ndmpd_save_nlist_v3:751]:name "NULL" 2/16 17:06:03 DEBUG: [5][ndmpd_save_nlist_v3:752]:node -1 2/16 17:06:03 DEBUG: [5][ndmpd_save_nlist_v3:753]:fh_info -1 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_getenv_zfs_backup_size:1639]:ZFS_BACKUP_SIZE: 2152710680 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_getenv_level:1570]:env(LEVEL): "0" 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_getenv_zfs_mode:1456]:env(ZFS_MODE) not specified, defaulting to recursive 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_getenv_zfs_force:1524]:env(ZFS_FORCE) not specified, defaulting to FALSE 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_getenv_update:1596]:env(UPDATE): "y" 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_getenv_dmp_name:1610]:env(DMP_NAME) not specified, defaulting to 'level' 2/16 17:06:03 DEBUG: [5][ndmpd_zfs_restore_pathvalid:1331]:restore path: fridge/restore162 2/16 17:06:03 DEBUG: [5][ndmp_send_request:458]:handler->mh_xdr_reply == 0 2/16 17:06:03 NOTICE: [5][ndmpd_zfs_dma_log:2436]:'zfs' recover starting 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1280]:no more messages in stream buffer 2/16 17:06:03 DEBUG: [7][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [0, 0, 0, 0, 0] 2/16 17:06:03 DEBUG: [7][ndmpd_remote_read_v3:1836]:to NOTIFY_DATA_READ [0, 18446744073709551615] 2/16 17:06:03 DEBUG: [7][ndmp_send_request:458]:handler->mh_xdr_reply == 0 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1172]:reply_expected: FALSE 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1252]:received request: 0x400 2/16 17:06:03 DEBUG: [5][ndmp_process_messages:1280]:no more messages in stream buffer 2/16 17:06:03 DEBUG: [7][ndmpd_zfs_header_read:443]:tape header: NDMPUTF8MAGIC; 0 0; 64512 2/16 17:06:03 DEBUG: [8][ndmpd_zfs_restore_recv_write:913]:nz_zfs_force: 0 2/16 17:06:03 DEBUG: [9][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [18446744073709487103, 0, 18446744073709551615, 64512, 0] 2/16 17:06:03 DEBUG: [9][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [18446744073709422591, 0, 18446744073709551615, 129024, 0] 2/16 17:06:03 DEBUG: [9][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [18446744073709358079, 0, 18446744073709551615, 193536, 0] 2/16 17:06:03 DEBUG: [9][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [18446744073709293567, 0, 18446744073709551615, 258048, 0] 2/16 17:06:03 DEBUG: [9][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [18446744073709229055, 0, 18446744073709551615, 322560, 0] 2/16 17:06:03 DEBUG: [9][ndmpd_remote_read_v3:1781]:ns_data.dd_xx: [18446744073709164543, 0, 18446744073709551615, 387072, 0]