Symptoms

Vertias/NetBackup reports NDMP backup failures: Dec 12, 2020 6:46:52 PM - Error ndmpagent (pid=13552) read from socket returned -1 10054 (An existing connection was forcibly closed by the remote host.) Dec 12, 2020 6:46:54 PM - Error ndmpagent (pid=13552) MOVER_HALTED unexpected reason = 4 (NDMP_MOVER_HALT_CONNECT_ERROR) Dec 12, 2020 6:46:56 PM - Error ndmpagent (pid=13552) NDMP backup failed, path = /ifs/data/share Dec 12, 2020 6:46:58 PM - Info bptm (pid=14344) EXITING with status 99 Dec 12, 2020 6:46:58 PM - Info ndmpagent (pid=0) done. status: 114: unimplemented error code 114 Dec 12, 2020 6:46:58 PM - end writing; write time: 10:39:00 The Isilon reports that the same backup completed without fault (based from the time stamp of the failed job). An event in /var/log/messages shows a snapshot is getting deleted, and Isilon-specific errors aren't included. 2020-12-12T18:46:43-06:00 isilon-5(id5) /boot/kernel.amd64/kernel: [stf_syscall.c:1777](pid 9582="isi_ndmp_d")(tid=103487) ifs_snap_delete_start: Deleting snapshot 613716 NDMP session 9582 provides evidence of a sucessful backup: Sat Dec 12 08:08:00 2020 (1607782080): Received from x.x.x.x; Session:9582 Message : 0x401 (NDMP_DATA_START_BACKUP) Timestamp : 1607782080 XSequence : 11 RSequence : 0 Error : 0 (NDMP_NO_ERR) Bkup type : dump Num Env. Var : 6 Name (value) : TYPE (dump) Name (value) : FILESYSTEM (/ifs/data/share) Name (value) : PREFIX (/ifs/data/share) Name (value) : LEVEL (0) Name (value) : HIST (y) Name (value) : UPDATE (y) Sat Dec 12 08:08:00 2020 (1607782080): Transmitted to x.x.x.x; Session:9582 Message : 0x401 (NDMP_DATA_START_BACKUP) Timestamp : 1607782080 XSequence : 12 RSequence : 11 Error : 0 (NDMP_NO_ERR) Error : 0 (NDMP_NO_ERR) --output omitted-- Sat Dec 12 18:46:43 2020 (1607820403): Transmitted to x.x.x.x; Session:9582 Message : 0x603 (NDMP_LOG_MESSAGE) Timestamp : 1607820403 XSequence : 10947 RSequence : 0 Error : 0 (NDMP_NO_ERR) Type : 0 (NORMAL) Msg ID : 1607820403 Log : Filetransfer: Transferred 5948426974208 bytes in 38322.706 seconds throughput of 151581.433 KB/s Total 5948426974208 bytes in this backup stream Sat Dec 12 18:46:43 2020 (1607820403): Transmitted to x.x.x.x; Session:9582 Message : 0x603 (NDMP_LOG_MESSAGE) Timestamp : 1607820403 XSequence : 10948 RSequence : 0 Error : 0 (NDMP_NO_ERR) Type : 0 (NORMAL) Msg ID : 1607820403 Log : CPU user=708.291926 sys=10039.104244 ft=38322.654260 cdb=0.000000 maxrss=209468 in=728356105 out=29 vol=165048572 inv=21379155 Sat Dec 12 18:46:43 2020 (1607820403): Transmitted to x.x.x.x; Session:9582 Message : 0x603 (NDMP_LOG_MESSAGE) Timestamp : 1607820403 XSequence : 10949 RSequence : 0 Error : 0 (NDMP_NO_ERR) Type : 0 (NORMAL) Msg ID : 1607820403 Log : Objects (scanned/included): ---------------------------- Regular Files(scan/incl(reg/worm/sparse)): (4396861/4396861(4396861/0/0)) Stub Files(scan/incl(stub/reg/combo)): (0/0(0/0/0)) Directories : (16967/16967) ADS Entries : (718/718) Soft Links(scan/incl(slink/worm)) : (0/0(0/0)) Hard Links : (0/0) Block Devices : (0/0) Char Devices : (0/0) FIFO : (0/0) Sockets : (0/0) Whiteout : (0/0) Unknown : (0/0) Sat Dec 12 18:46:43 2020 (1607820403): Transmitted to x.x.x.x; Session:9582 Message : 0x603 (NDMP_LOG_MESSAGE) Timestamp : 1607820403 XSequence : 10950 RSequence : 0 Error : 0 (NDMP_NO_ERR) Type : 0 (NORMAL) Msg ID : 1607820403 Log : Dir Depth (count) ---------------------------- Total Dirs: 16967 Max Depth: 8 Sat Dec 12 18:46:43 2020 (1607820403): Transmitted to x.x.x.x; Session:9582 Message : 0x603 (NDMP_LOG_MESSAGE) Timestamp : 1607820403 XSequence : 10951 RSequence : 0 Error : 0 (NDMP_NO_ERR) Type : 0 (NORMAL) Msg ID : 1607820403 Log : File History ---------------------------- Num FH_HIST_FILE messages: 4413828 Num FH_HIST_DIR messages: 0 Num FH_HIST_NODE messages: 0 Sat Dec 12 18:46:44 2020 (1607820404): Transmitted to x.x.x.x; Session:9582 Message : 0x501 (NDMP_NOTIFY_DATA_HALTED) Timestamp : 1607820404 XSequence : 10952 RSequence : 0 Error : 0 (NDMP_NO_ERR) Reason : 1 (NDMP_DATA_HALT_SUCCESSFUL) Sat Dec 12 18:46:58 2020 (1607820418): Received from x.x.x.x; Session:9582 Message : 0x400 (NDMP_DATA_GET_STATE) Timestamp : 1607820418 XSequence : 1286 RSequence : 0 Error : 0 (NDMP_NO_ERR) Sat Dec 12 18:46:58 2020 (1607820418): Transmitted to x.x.x.x; Session:9582 Message : 0x400 (NDMP_DATA_GET_STATE) Timestamp : 1607820418 XSequence : 10953 RSequence : 1286 Error : 0 (NDMP_NO_ERR) Unsupported : 3 Error : 0 (NDMP_NO_ERR) OP : 1 (BACKUP) State : 2 (HALTED) Halt Reason : 1 (NDMP_DATA_HALT_SUCCESSFUL) Bytes Processed (H L) : (1384 4194333696) 5948429071360 Bytes remaining (H L) : (0 0) 0 Time Remain : 0 Data Conn: Type : 1 (TCP) Addr count : 1 IP Addr : (0xa327607) x.x.x.x Port : 1836 Env len : 0 Read offset (H L) : (0 0) 0 Read length (H L) : (0 0) 0 Sat Dec 12 18:46:58 2020 (1607820418): Received from x.x.x.x; Session:9582 Message : 0x407 (NDMP_DATA_STOP) Timestamp : 1607820418 XSequence : 1287 RSequence : 0 Error : 0 (NDMP_NO_ERR) Sat Dec 12 18:46:58 2020 (1607820418): Transmitted to x.x.x.x; Session:9582 Message : 0x407 (NDMP_DATA_STOP) Timestamp : 1607820418 XSequence : 10954 RSequence : 1287 Error : 0 (NDMP_NO_ERR) Error : 0 (NDMP_NO_ERR) Sat Dec 12 18:46:58 2020 (1607820418): Received from x.x.x.x; Session:9582 Message : 0x902 (NDMP_CONNECT_CLOSE) Timestamp : 1607820418 XSequence : 1288 RSequence : 0 Error : 0 (NDMP_NO_ERR)

Cause

This is caused by an incorrectly configured network variable on the Isilon. OneFS sends an RST flag at the end of the data connection without confirmation that we sent all the data in the SendQ buffer.

Resolution

The OneFS June 2021 and later RUPs contains the fix. The recommendation is to go to our support site regularly to check for updates. If Dell's assistance is requested with the patch installation, a case can get opened with our Remote Proactive Services team who specializes in upgrades.

Support Cases