error code 174 and 40 intermittently on SAN client backup

[tarmizi]

Hi all,

We are having this problem for sometime now and still cannot resolve it. The SAN client backup giving us error code 174 and 40 when performing backup. We did found an article (https://www.veritas.com/support/en_US/article.000010982) it very similar to what are currently facing. We have follow the workaround and in the midst of finding the dvice driver version of the SAN client. And here is my question, have anyone faced this kind problem? and what are the solution?

Environment:

Netbackup master: version 7.6.1.2

Netbackup appliance (media): version 2.6.1.2

Client (AIX 6.1): version 7.6.1

Oracle 11g

Error code 40:

8/23/2017 10:26:26 AM - Info bpbrm(pid=130684) xxx is the host to backup data from
8/23/2017 10:26:26 AM - Info bpbrm(pid=130684) reading file list for client
8/23/2017 10:26:26 AM - Info bpbrm(pid=130684) accelerator enabled
8/23/2017 10:26:32 AM - Info bpbrm(pid=130684) There is no complete backup image match with track journal, a regular full backup will be performed.
8/23/2017 10:26:33 AM - Info bpbrm(pid=130684) starting bpbkar on client
8/23/2017 10:26:33 AM - Info bpbkar(pid=22413510) Backup started
8/23/2017 10:26:33 AM - Info bpbrm(pid=130684) bptm pid: 130703
8/23/2017 10:26:33 AM - Info bptm(pid=130703) start
8/23/2017 10:26:34 AM - Info bptm(pid=130703) using 262144 data buffer size
8/23/2017 10:26:34 AM - Info bptm(pid=130703) using 16 data buffers
8/23/2017 10:26:34 AM - Info bptm(pid=130703) USING 262144 data buffer size for FT
8/23/2017 10:26:38 AM - Info bptm(pid=130703) start backup
8/23/2017 11:46:56 AM - Error bpbrm(pid=130684) from client xxx: ERR - bpbkar exiting because backup is aborting
8/23/2017 11:46:58 AM - Error bptm(pid=130703) media manager terminated by parent process
8/23/2017 11:47:14 AM - Info nbjm(pid=6352) starting backup job (jobid=36202) for client xxx, policy xxx_FS_DAILY, schedule FS_Daily_CORE
8/23/2017 11:47:14 AM - Info nbjm(pid=6352) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=36202, request id:{9F947E8E-32DA-4054-AEBA-F05C3C591259})
8/23/2017 11:47:14 AM - requesting resource stu_disk_xxxxx
8/23/2017 11:47:14 AM - requesting resource masterserver.NBU_CLIENT.MAXJOBS.xxx
8/23/2017 11:47:14 AM - requesting resource masterserver.NBU_POLICY.MAXJOBS.xxx_FS_DAILY
8/23/2017 11:47:15 AM - granted resource masterserver.NBU_CLIENT.MAXJOBS.xxx
8/23/2017 11:47:15 AM - granted resource masterserver.NBU_POLICY.MAXJOBS.xxx_FS_DAILY
8/23/2017 11:47:15 AM - granted resource MediaID=@aaaak;DiskVolume=PureDiskVolume;DiskPool=dp_disk_xxxxx;Path=PureDiskVolume;StorageServer=xxxxx;MediaServer=xxxxx
8/23/2017 11:47:15 AM - granted resource stu_disk_xxxxx
8/23/2017 11:47:15 AM - granted resource TRANSPORT
8/23/2017 11:47:15 AM - estimated 48930505 Kbytes needed
8/23/2017 11:47:15 AM - Info nbjm(pid=6352) started backup (backupid=xxx_1503460035) job for client xxx, policy xxx_FS_DAILY, schedule FS_Daily_CORE on storage unit stu_disk_xxxxx
8/23/2017 11:47:17 AM - started process bpbrm (130684)
8/23/2017 11:47:23 AM - connecting
8/23/2017 11:47:24 AM - connected; connect time: 0:00:01
8/23/2017 11:47:25 AM - Opening Fibre Transport Connection, Backup Id: xxx_1503460035
8/23/2017 11:47:42 AM - begin writing
8/23/2017 11:47:58 AM - Info xxxxx(pid=130703) StorageServer=PureDisk:xxxxx; Report=PDDO Stats for (xxxxx): scanned: 38981979 KB, CR sent: 5799004 KB, CR sent over FC: 0 KB, dedup: 85.1%, cache disabled
8/23/2017 11:48:00 AM - Info bpbkar(pid=22413510) done. status: 40: network connection broken
8/23/2017 1:08:52 PM - end writing; write time: 1:21:10
network connection broken (40)

Erro code 174:

8/22/2017 6:10:24 PM - Info bpbrm(pid=38435) xxx is the host to backup data from
8/22/2017 6:10:24 PM - Info bpbrm(pid=38435) reading file list for client
8/22/2017 6:10:25 PM - Info bpbrm(pid=38435) listening for client connection
8/22/2017 6:10:26 PM - Info bpbrm(pid=38435) INF - Client read timeout = 5400
8/22/2017 6:10:26 PM - Info bpbrm(pid=38435) accepted connection from client
8/22/2017 6:10:27 PM - Info dbclient(pid=13762636) Backup started
8/22/2017 6:10:27 PM - Info bpbrm(pid=38435) bptm pid: 38489
8/22/2017 6:10:27 PM - Info bptm(pid=38489) start
8/22/2017 6:10:28 PM - Info bptm(pid=38489) using 262144 data buffer size
8/22/2017 6:10:28 PM - Info bptm(pid=38489) using 16 data buffers
8/22/2017 6:10:28 PM - Info bptm(pid=38489) USING 262144 data buffer size for FT
8/22/2017 6:10:30 PM - Info bptm(pid=38489) start backup
8/22/2017 6:10:37 PM - Info dbclient(pid=13762636) dbclient(pid=13762636) wrote first buffer(size=262144)
8/22/2017 6:10:56 PM - Info dbclient(pid=13762636) done. status: 6
8/22/2017 6:10:56 PM - Critical bptm(pid=38489) data buffers out of sequence, expected number 5275, received 5278
8/22/2017 6:10:59 PM - Info bptm(pid=38489) EXITING with status 174 <----------
8/22/2017 6:10:59 PM - Info dbclient(pid=13762636) done. status: 174: media manager - system error occurred
8/22/2017 7:31:01 PM - Info nbjm(pid=6352) starting backup job (jobid=35405) for client xxx, policy CORE_JURISDB_ORA_FULL_adv_disk, schedule Default-Application-Backup
8/22/2017 7:31:01 PM - Info nbjm(pid=6352) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=35405, request id:{8D85BFA3-4CA1-4CD1-A108-2732F8EE22C8})
8/22/2017 7:31:01 PM - requesting resource stu_adv_xxxxx
8/22/2017 7:31:01 PM - requesting resource masterserver.NBU_CLIENT.MAXJOBS.xxx
8/22/2017 7:31:01 PM - requesting resource xxxxxx.NBU_POLICY.MAXJOBS.CORE_JURISDB_ORA_FULL_adv_disk
8/22/2017 7:31:05 PM - granted resource masterserver.NBU_CLIENT.MAXJOBS.xxx
8/22/2017 7:31:05 PM - granted resource masterserver.NBU_POLICY.MAXJOBS.CORE_JURISDB_ORA_FULL_adv_disk
8/22/2017 7:31:05 PM - granted resource MediaID=@aaaal;DiskVolume=/advanceddisk/dp1/advol;DiskPool=dp_adv_xxxxx;Path=/advanceddisk/dp1/advol;StorageServer=xxxxx;MediaServer=xxxxx
8/22/2017 7:31:05 PM - granted resource stu_adv_xxxxx
8/22/2017 7:31:05 PM - granted resource TRANSPORT
8/22/2017 7:31:08 PM - estimated 0 Kbytes needed
8/22/2017 7:31:08 PM - Info nbjm(pid=6352) started backup (backupid=SACBA325_1503401468) job for client xxx, policy CORE_JURISDB_ORA_FULL_adv_disk, schedule Default-Application-Backup on storage unit stu_adv_xxxxx
8/22/2017 7:31:09 PM - started process bpbrm (38435)
8/22/2017 7:31:10 PM - connecting
8/22/2017 7:31:12 PM - connected; connect time: 0:00:02
8/22/2017 7:31:15 PM - Opening Fibre Transport Connection, Backup Id: xxx_1503401468
8/22/2017 7:31:16 PM - begin writing
8/22/2017 7:31:45 PM - end writing; write time: 0:00:29
media manager - system error occurred (174)

[Thiago_Ribeiro]

Hi

Is your backup policy type a VMware or Oracle?

Im asking because I saw this message..Are you enabled accelerator?

8/23/2017 10:26:26 AM - Info bpbrm(pid=130684) xxx is the host to backup data from
8/23/2017 10:26:26 AM - Info bpbrm(pid=130684) reading file list for client
8/23/2017 10:26:26 AM - Info bpbrm(pid=130684) accelerator enabled
8/23/2017 10:26:32 AM - Info bpbrm(pid=130684) There is no complete backup image match with track journal, a regular full backup will be performed.

Regards,

Thiago

[Marianne]

I see a couple of 'strange' things in Job Details: 
bpbkar process started on client (not dbclient).

Status 40
accelerator enabled
DiskVolume=PureDiskVolume

Status 174
DiskVolume=/advanceddisk

You seem to be backing up Oracle dumps instead of doing rman backups, right?

Status 40 with SAN client seems weird seeing that the status code is associated with network errors. Could be network errors associated with catalog metadata updates...
I have seen recommendations to send SAN client backup to Advanced Disk, not to dedupe.
Verbose bpbrm log on Appliance bpbrm and bpbkar on client may shed more light on possible cause for status 40.

For status 174, you will need the logs as per the TN. 

PS: 
Please upgrade your environment as all versions up to 7.6.x reached EOSL more than 6 months ago.

[mattedia]

Hi to all ..

Hi have the same problem in my enviroment , only in FT transport mode .
Master RH 7.2 --> NBU 8.0
MEDIA Appliancen 5240 3.0.0 --> NBU 8.0


Nov 20, 2017 1:02:45 AM - Info nbjm (pid=27762) starting backup job (jobid=8729490) for client sapxxxx, policy sap048, schedule App-Archive
Nov 20, 2017 1:02:45 AM - Info nbjm (pid=27762) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=8729490, request id:{22F226C8-CD86-11E7-9A47-AF7AF5356927})
Nov 20, 2017 1:02:45 AM - requesting resource su_FC_STORAGE
Nov 20, 2017 1:02:45 AM - requesting resource MASTER.NBU_CLIENT.MAXJOBS.sapxxxx
Nov 20, 2017 1:02:45 AM - requesting resource MASTER.NBU_POLICY.MAXJOBS.sapxxxx
Nov 20, 2017 1:02:46 AM - awaiting resource su_FC_STORAGE. Waiting for resources.
Reason: FT pipes are in use, Media server:STORAGE,
Robot Type(Number): NONE(N/A), Media ID: N/A, Drive Name: N/A,
Volume Pool: NetBackup, Storage Unit: su_FC_STORAGE, Drive Scan Host: N/A,
Disk Pool: dp_STORAGE, Disk Volume: PureDiskVolume
Nov 20, 2017 1:03:28 AM - granted resource MASTER.NBU_CLIENT.MAXJOBS.sapxxxx
Nov 20, 2017 1:03:28 AM - granted resource MASTER.NBU_POLICY.MAXJOBS.sapxxxx
Nov 20, 2017 1:03:28 AM - granted resource MediaID=@aaaac;DiskVolume=PureDiskVolume;DiskPool=dp_STORAGE;Path=PureDiskVolume;StorageServer=STORAGE;MediaServer=STORAGE
Nov 20, 2017 1:03:28 AM - granted resource su_FC_STORAGE
Nov 20, 2017 1:03:28 AM - granted resource TRANSPORT
Nov 20, 2017 1:03:28 AM - estimated 0 kbytes needed
Nov 20, 2017 1:03:28 AM - Info nbjm (pid=27762) started backup (backupid=sapxxxx_1511136208) job for client sapxxxx, policy sapxxxx, schedule App-Archive on storage unit su_FC_STORAGE
Nov 20, 2017 1:03:28 AM - started process bpbrm (pid=292094)
Nov 20, 2017 1:03:29 AM - Info bpbrm (pid=292094)sapxxxx is the host to backup data from
Nov 20, 2017 1:03:29 AM - Info bpbrm (pid=292094) reading file list for client
Nov 20, 2017 1:03:29 AM - connecting
Nov 20, 2017 1:03:30 AM - Info bpbrm (pid=292094) listening for client connection
Nov 20, 2017 1:03:31 AM - Info bpbrm (pid=292094) INF - Client read timeout = 3600
Nov 20, 2017 1:03:31 AM - Info bpbrm (pid=292094) accepted connection from client
Nov 20, 2017 1:03:31 AM - Info dbclient (pid=18022508) Backup started
Nov 20, 2017 1:03:31 AM - Info bpbrm (pid=292094) bptm pid: 292210
Nov 20, 2017 1:03:31 AM - connected; connect time: 0:00:00
Nov 20, 2017 1:03:32 AM - Info bptm (pid=292210) start
Nov 20, 2017 1:03:32 AM - Info bptm (pid=292210) using 262144 data buffer size
Nov 20, 2017 1:03:32 AM - Info bptm (pid=292210) setting receive network buffer to 262144 bytes
Nov 20, 2017 1:03:32 AM - Info bptm (pid=292210) using 16 data buffers
Nov 20, 2017 1:03:32 AM - Info bptm (pid=292210) USING 262144 data buffer size for FT
Nov 20, 2017 1:03:33 AM - Opening Fibre Transport connection, Backup Id: sapxxxx_1511136208
Nov 20, 2017 1:03:34 AM - Info bptm (pid=292210) start backup
Nov 20, 2017 1:03:35 AM - begin writing
Nov 20, 2017 1:03:41 AM - Info dbclient (pid=18022508) dbclient(pid=18022508) wrote first buffer(size=262144)
Nov 20, 2017 1:03:41 AM - Info dbclient (pid=18022508) done. status: 6
Nov 20, 2017 1:03:41 AM - Critical bptm (pid=292210) data buffers out of sequence, expected number 9, received 12
Nov 20, 2017 1:03:44 AM - Info bptm (pid=292210) EXITING with status 174 <----------
Nov 20, 2017 1:03:44 AM - Info STORAGE (pid=292210) StorageServer=PureDisk:STORAGE; Report=PDDO Stats for (STORAGE): scanned: 2051 KB, CR sent: 729 KB, CR sent over FC: 0 KB, dedup: 64.5%, cache hits: 0 (0.0%)
Nov 20, 2017 1:03:44 AM - Info dbclient (pid=18022508) done. status: 174: media manager - system error occurred
Nov 20, 2017 1:03:44 AM - end writing; write time: 0:00:09
media manager - system error occurred (174)