NDMP using Arcserve fails with 'NDMP_TIMEOUT_ERR' and 'NDMP_DATA_HALT_INTERNAL_ERROR'

Last updated
Save as PDF
Share
1. Share
2. Tweet
3. Share

Views:: 180

Visibility:: Public

Votes:: 0

Category:: ndmp

Specialty:: dp

Last Updated:

Applies to

ONTAP 9
NDMP - SVM-scope
Arcserve

Issue

NDMP backup using Arcserve backup application fails with 'NDMP_TIMEOUT_ERR' and 'NDMP_DATA_HALT_INTERNAL_ERROR'
From Arcserve logs it seems some of the "NDMP4_DATA_GET_STATE" requests were not being responded to
NetApp Backup logs - indicates that the backup completed successfully:

dmp Tue Jan 3 09:28:00 EST 2023 ***(0) Phase_change (IV) dmp Tue Jan 3 18:29:53 EST 2023 ***(0) Phase_change (V) dmp Tue Jan 3 18:29:53 EST 2023 ***(0) Tape_close (ndmp) dmp Tue Jan 3 18:29:53 EST 2023 ***(0) End (11234458 MB, 34054 secs, 329 MBps)

NetApp NDMP debug logs - the backup completes but Arcserve continues to send "NDMP4_DATA_GET_STATE" request for hours
Every "NDMP4_DATA_GET_STATE" requests was responded to
The backup is eventually aborted by the admin in Arcserve

NDMP log excerpt:
NetApp NDMP server reporting that it has successfully completed the backup:
Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: DMA<<S V4 sequence=179408 (0x2bcd0) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: Time_stamp=0x63b4ba71 (Jan 3 18:29:53 2023) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message type=0 (NDMP4_MESSAGE_REQUEST) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message_code=0x603 (NDMP4_LOG_MESSAGE) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: reply_sequence=0 (0x0) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: error_code=0 (NDMP4_NO_ERR) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: log_type=0 (NDMP4_LOG_NORMAL) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message_id=132 (0x84) Tue Jan 03 2023 18:29:53 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: entry='DUMP: DUMP IS DONE\n

Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: DMA<<S V4 sequence=179412 (0x2bcd4) Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: Time_stamp=0x63b4ba72 (Jan 3 18:29:54 2023) Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message type=0 (NDMP4_MESSAGE_REQUEST) Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message_code=0x501 (NDMP4_NOTIFY_DATA_HALTED) Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: reply_sequence=0 (0x0) Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: error_code=0 (NDMP4_NO_ERR) Tue Jan 03 2023 18:29:54 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: reason=1 (NDMP4_DATA_HALT_SUCCESSFUL)

Arcserve still sending "NDMP4_DATA_GET_STATE" requests ~21 hours after NDMP server reported that the backup has completed successfully:
Wed Jan 04 2023 15:00:58 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: DMA>>S V4 sequence=191 (0xbf) Wed Jan 04 2023 15:00:58 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: Time_stamp=0x63b5dafa (Jan 4 15:00:58 2023) Wed Jan 04 2023 15:00:58 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message type=0 (NDMP4_MESSAGE_REQUEST) Wed Jan 04 2023 15:00:58 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: message_code=0x400 (NDMP4_DATA_GET_STATE) Wed Jan 04 2023 15:00:58 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: reply_sequence=0 (0x0) Wed Jan 04 2023 15:00:58 -05:00 [kern_ndmpd:info:6161] [12345] DEBUG: error_code=0 (NDMP4_NO_ER