NetBackup optimized duplication failed, events out of sequence - image inconsistency (229) in version 8.3.0.1, 8.3.0.2, and 9.1.0.1

Problem

For an issue to be considered a match to the one described in this article, all the following must be true:

• The backup is TIR enabled and must be an Incremental. (Full backups are not affected).
• The issue only occurs during an optimized duplication between MSDP storage servers.
• The image in question successfully duplicates to tape.

Error Message

Activity Monitor > Job Details:

Jun 7, 2021 4:04:07 PM - begin writing
Jun 7, 2021 4:04:07 PM - Info bpdm (pid=213409) Waiting for storage server pnbuxxxxxx, disk volume PureDiskVolume
Jun 7, 2021 4:04:32 PM - Error bpduplicate (pid=16264) host xxxx.xxxx.local backup id nbuxxxxxxxx_1619614801 optimized duplication failed, events out of sequence - image inconsistency (229).
Jun 7, 2021 4:04:32 PM - Error bpduplicate (pid=16264) Duplicate of backupid nbuxxxxxxxx_1619614801 failed, events out of sequence - image inconsistency (229).
Jun 7, 2021 4:04:32 PM - Error bpduplicate (pid=16264) Status = no images were successfully processed.
Jun 7, 2021 4:04:32 PM - end Duplicate; elapsed time 0:01:12
Jun 7, 2021 4:05:07 PM - end writing; write time: 0:01:00
Jun 7, 2021 4:05:08 PM - Info xxxx.xxxx.local (pid=213409) StorageServer=PureDisk:pnbuxxxxxx; Report=PDDO Stats for (pnbuxxxxxx): scanned: 4983319 KB, CR sent: 3135 KB, CR sent over FC: 0 KB, dedup: 99.9%, cache disabled, where dedup space saving:99.9%, compression space saving:0.0%
Jun 7, 2021 4:05:08 PM - Error bpdm (pid=213409) read of image metadata file failed: events out of sequence - image inconsistency
no images were successfully processed  (191)

Primary/Master Server bpdbm logs show:

16:04:30.357 [14136.15348] <2> fetch_DBM_Image: derGeneratedID=''
16:04:30.357 [14136.15348] <2> ImageReadMetadata::~ImageReadMetadata: Exiting
16:04:30.357 [14136.15348] <8> DbmOdbcConnect::rollbackTransaction: (35286) success - view count 1
16:04:30.357 [14136.15348] <2> DbmOdbcView::~DbmOdbcView: (35286.47) Exiting
16:04:30.357 [14136.15348] <2> DbmOdbcConnect::~DbmOdbcConnect: (35286) Exiting
16:04:30.357 [14136.15348] <2> DbmOdbcConnectManager::releaseConnection: Returning connection 000000000167DD50 (35286) to the cache, isolationLevel(32)
16:04:30.357 [14136.15348] <2> process_request: request complete: exit status 229 events out of sequence - image inconsistency; query type: 93
16:04:30.357 [14136.15348] <2> DbmCaching::get<unsigned int>: Value for dbm_cache_generation served from cache: (565)

Media Server bpdm logs show:

16:05:08.407 [213409] <2> write_data_tir_or_im: buffer for im write, origbuf = 0x0x1ed7850, BUF_PTR = 0x0x1ed8000, BUFF_SIZE = 262144
16:05:08.407 [213409] <2> ConnectionCache::connectAndCache: Acquiring new connection for host xxxmaster, query type 93
...(snip)...
16:05:08.431 [213409] <2> logconnections: BPDBM CONNECT FROM 127.0.0.1.33682 TO 127.0.0.1.34434 fd = 19
16:05:08.464 [213409] <2> setup_tir_or_im_read: string received from bpdbm is (229 -1)
16:05:08.464 [213409] <2> closeConnection: Closing connection for query type 93 - cannot be reused
...(snip)...
16:05:08.510 [213409] <2> set_job_details: Tfile (865582): LOG 1623053108 16 bpdm 213409 read of image metadata file failed: events out of sequence - image inconsistency

Cause

The failure occurs due to a check looking for TIR info at a place where it is not needed.

Solution

A hotfix is now available for this issue in the current version(s) of the product(s) mentioned. Refer to the Hotfix link under Related Articles to obtain the hotfix needed to resolve the issue.

EEBs are available to resolve:

• ET 4041458 (NetBackup 8.3.0.1)
• ET 4078034 (NetBackup 8.3.0.2)
• ET 4081110 (NetBackup 9.1.0.1)

This issue is formerly fixed  in NetBackup 10.0