cancel
Showing results for 
Search instead for 
Did you mean: 

Info bpbkar32(pid=6172) done. status: 52: timed out waiting for media manager to mount volume

soeheinhtut
Level 4

Please help to check below failed job and how can i resolved and prevent in future?

image.png

==========================================================================================

12/21/2019 2:41:33 AM - Info nbjm(pid=4068) starting backup job (jobid=23613) for client abcoai-bkup01p, policy DATA-ACC-lto-17, schedule Full
12/21/2019 2:41:33 AM - Info nbjm(pid=4068) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=23613, request id:{771DE47C-20ED-4A45-BC58-C194575575CD})
12/21/2019 2:41:33 AM - requesting resource abcoai-LTO-OA
12/21/2019 2:41:33 AM - requesting resource abcoai-bkmg01p.NBU_CLIENT.MAXJOBS.abcoai-bkup01p
12/21/2019 2:41:33 AM - requesting resource abcoai-bkmg01p.NBU_POLICY.MAXJOBS.DATA-ACC-lto-17
12/21/2019 2:41:33 AM - granted resource abcoai-bkmg01p.NBU_CLIENT.MAXJOBS.abcoai-bkup01p
12/21/2019 2:41:33 AM - granted resource abcoai-bkmg01p.NBU_POLICY.MAXJOBS.DATA-ACC-lto-17
12/21/2019 2:41:33 AM - granted resource CBMA17
12/21/2019 2:41:33 AM - granted resource HP.ULTRIUM6-SCSI.001
12/21/2019 2:41:33 AM - granted resource abcoai-LTO-OA
12/21/2019 2:41:33 AM - estimated 0 Kbytes needed
12/21/2019 2:41:33 AM - Info nbjm(pid=4068) started backup (backupid=abcoai-bkup01p_1576872693) job for client abcoai-bkup01p, policy DATA-ACC-lto-17, schedule Full on storage unit abcoai-LTO-OA
12/21/2019 2:41:46 AM - started process bpbrm (7888)
12/21/2019 2:42:04 AM - Info bpbrm(pid=7888) abcoai-bkup01p is the host to backup data from
12/21/2019 2:42:09 AM - Info bpbrm(pid=7888) reading file list for client
12/21/2019 2:42:09 AM - connecting
12/21/2019 2:42:23 AM - Info bpbrm(pid=7888) starting bpbkar32 on client
12/21/2019 2:42:23 AM - Info bpbkar32(pid=6172) Backup started
12/21/2019 2:42:23 AM - Info bpbkar32(pid=6172) change time comparison:<disabled>
12/21/2019 2:42:23 AM - Info bpbkar32(pid=6172) archive bit processing:<enabled>
12/21/2019 2:42:23 AM - connected; connect time: 0:00:14
12/21/2019 2:42:23 AM - Info bptm(pid=7720) start
12/21/2019 2:42:45 AM - Info bptm(pid=7720) using 65536 data buffer size
12/21/2019 2:42:45 AM - Info bptm(pid=7720) setting receive network buffer to 263168 bytes
12/21/2019 2:42:45 AM - Info bptm(pid=7720) using 30 data buffers
12/21/2019 2:42:59 AM - Info bptm(pid=7720) start backup
12/21/2019 2:42:59 AM - Info bptm(pid=7720) Waiting for mount of media id CBMA17 (copy 1) on server abcoai-bkup01p.
12/21/2019 2:42:59 AM - mounting CBMA17
12/21/2019 2:44:14 AM - Info bptm(pid=7720) media id CBMA17 mounted on drive index 1, drivepath {4,0,0,0}, drivename HP.ULTRIUM6-SCSI.001, copy 1
12/21/2019 2:44:19 AM - mounted; mount time: 0:01:20
12/21/2019 2:44:23 AM - positioning CBMA17 to file 1
12/21/2019 2:47:12 AM - positioned CBMA17; position time: 0:02:49
12/21/2019 2:47:12 AM - begin writing
12/21/2019 2:52:28 AM - Info bpbkar32(pid=6172) done. status: 52: timed out waiting for media manager to mount volume
12/21/2019 2:52:28 AM - end writing; write time: 0:05:16
timed out waiting for media manager to mount volume(52)

31 REPLIES 31

Pls check below today bptm logs, 

Already restart services and reboot media server last two days ago

09:49:42.948 [1180.5452] <2> initialize: fd values STDOUTSOCK=352 STDERRSOCK=484
09:49:42.948 [1180.5452] <4> RedirectNBLoggerToLegacyLog: Setting up redirection of VxUL messages to legacy log
09:49:42.963 [1180.5452] <4> RedirectNBLoggerToLegacyLog: Verbosity from VxUL configuration: 0
09:49:42.963 [1180.5452] <4> RedirectNBLoggerToLegacyLog: logmsg verbosity set: 0
09:49:47.604 [1180.5452] <4> bptm: emmserver_name = xxx-bkmg01p
09:49:47.604 [1180.5452] <4> bptm: emmserver_port = 1556
09:50:13.871 [1180.5452] <4> report_client: VBRC 2 1180 1 xxx-bkup01p_1583810334 13 DATA-ACC-lto-04 0 Full 0 1 1
09:51:33.576 [1180.5452] <4> report_throughput: VBRT 1 1180 1 1 HP.ULTRIUM6-SCSI.001 CBMA04 2 1 0 0 0 (bptm.c.18469)
09:51:44.951 [1180.5452] <4> write_backup: media id CBMA04 contains drive encrypted data
09:51:54.361 [1180.5452] <4> write_backup: begin writing encrypted backup id xxx-bkup01p_1583810334, copy 1, fragment 1, to media id CBMA04 on drive HP.ULTRIUM6-SCSI.001 (index 1)

sdo
Moderator
Moderator
Partner    VIP    Certified

There's nothing wrong in what you have posted.  All entries are status <2> and <4> which are both "info" statuses.  You want to look for <8> warnings, and <16> error, and <32> critical.

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@soeheinhtut 

If you are looking for logging level, you need to check the opening lines of bptm log.

Please wait until the backup fails again, then upload bpbkar and bptm logs as attachment. 

https://vstecs-my.sharepoint.com/:f:/g/personal/soeheinhtut_vstecs_co_th/EvzmP7a3AAFMkmHPAbEfYm0B8S6... 

This error "status: 52: timed out waiting for media manager to mount volume" happens again. Uploaded to the above link.

Pls kindly check and help. Thanks

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@soeheinhtut 

My company's security settings does not allow me to open your link. 

What are the size of the files? 
In all honesty, if the files are too big to upload here, then fellow forum members (with regular day-time jobs) may not have the time to sift through logs.

Please post all text in Job Details so that members who are able to open your link can locate timestamps and PIDs.

Job Details as below

3/12/2020 10:22:53 AM - Info nbjm(pid=4048) starting backup job (jobid=24639) for client cbmoai-bkup01p, policy DATA-ACC-lto-08, schedule Full
3/12/2020 10:22:53 AM - Info nbjm(pid=4048) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=24639, request id:{095158C3-BA89-4F8C-A74F-1F058C5FF76D})
3/12/2020 10:22:53 AM - requesting resource cbmoai-LTO-OA
3/12/2020 10:22:53 AM - requesting resource cbmoai-bkmg01p.NBU_CLIENT.MAXJOBS.cbmoai-bkup01p
3/12/2020 10:22:53 AM - requesting resource cbmoai-bkmg01p.NBU_POLICY.MAXJOBS.DATA-ACC-lto-08
3/12/2020 10:23:01 AM - awaiting resource cbmoai-LTO-OA - No drives are available
3/12/2020 10:24:51 AM - granted resource cbmoai-bkmg01p.NBU_CLIENT.MAXJOBS.cbmoai-bkup01p
3/12/2020 10:24:51 AM - granted resource cbmoai-bkmg01p.NBU_POLICY.MAXJOBS.DATA-ACC-lto-08
3/12/2020 10:24:51 AM - granted resource CBMA08
3/12/2020 10:24:51 AM - granted resource HP.ULTRIUM6-SCSI.001
3/12/2020 10:24:51 AM - granted resource cbmoai-LTO-OA
3/12/2020 10:24:51 AM - estimated 0 Kbytes needed
3/12/2020 10:24:51 AM - Info nbjm(pid=4048) started backup (backupid=cbmoai-bkup01p_1583985291) job for client cbmoai-bkup01p, policy DATA-ACC-lto-08, schedule Full on storage unit cbmoai-LTO-OA
3/12/2020 10:25:05 AM - started process bpbrm (68)
3/12/2020 10:25:24 AM - Info bpbrm(pid=68) cbmoai-bkup01p is the host to backup data from
3/12/2020 10:25:28 AM - Info bpbrm(pid=68) reading file list for client
3/12/2020 10:25:28 AM - connecting
3/12/2020 10:25:42 AM - Info bpbrm(pid=68) starting bpbkar32 on client
3/12/2020 10:25:42 AM - connected; connect time: 0:00:14
3/12/2020 10:25:43 AM - Info bpbkar32(pid=3496) Backup started
3/12/2020 10:25:43 AM - Info bpbkar32(pid=3496) change time comparison:<disabled>
3/12/2020 10:25:43 AM - Info bpbkar32(pid=3496) archive bit processing:<enabled>
3/12/2020 10:25:43 AM - Info bptm(pid=5752) start
3/12/2020 10:26:09 AM - Info bptm(pid=5752) using 65536 data buffer size
3/12/2020 10:26:09 AM - Info bptm(pid=5752) setting receive network buffer to 263168 bytes
3/12/2020 10:26:09 AM - Info bptm(pid=5752) using 30 data buffers
3/12/2020 10:26:23 AM - Info bptm(pid=5752) start backup
3/12/2020 10:26:23 AM - Info bptm(pid=5752) Waiting for mount of media id CBMA08 (copy 1) on server cbmoai-bkup01p.
3/12/2020 10:26:23 AM - mounting CBMA08
3/12/2020 10:27:36 AM - Info bptm(pid=5752) media id CBMA08 mounted on drive index 1, drivepath {4,0,0,0}, drivename HP.ULTRIUM6-SCSI.001, copy 1
3/12/2020 10:27:41 AM - mounted; mount time: 0:01:18
3/12/2020 10:27:45 AM - positioning CBMA08 to file 1
3/12/2020 10:30:34 AM - positioned CBMA08; position time: 0:02:49
3/12/2020 10:30:34 AM - begin writing
3/12/2020 10:35:47 AM - Info bpbkar32(pid=3496) done. status: 52: timed out waiting for media manager to mount volume
3/12/2020 10:35:48 AM - end writing; write time: 0:05:14
timed out waiting for media manager to mount volume(52)

continuous: bptm logs as attached

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@soeheinhtut 

Everything is still exactly as my posts of 2 months ago - the status 52 is 'red herring' because of all timeouts exactly the same - NBU incorrectly picks the 1st timeout that it sees when it is actually a client read timeout.

In bpbkar we see that you are backing up a CIFS share. 

Read speed from the network share seems to be very slow. 
When the backup starts, a few path names are sent through, and then nothing until the timeout occurs.

I have suggested the following 2 months ago:

Please increase media mount timeout to something like 15 minutes, and Client read timeout to 10 minutes (600).

If you are not willing to accept advice here, I will unsubscribe from this post.

pls, let me know only on the master server? For client read timeout, the media server also needs to change?

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Client connect, Client read and Media mount timeouts are only relevant on the media server.

 

Pls check below capture,  didn't see media mount timeout setting in media server. Only see the Client read timeout.

MediaTimeout.PNG

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

I just checked NBU Admin Guide I (Host Properties section).

It seems that Media Mount Timeout is a global setting that is controlled from the master and therefore applicable to all media servers: 

Media Mount Timeout
Specifies how long NetBackup waits for the requested media to be mounted, positioned,
and ready on backups, restores, and duplications.
This property applies to currently selected master servers.
Use this timeout to eliminate excessive waiting time during manual media mounts. (For
example, when robotic media is out of the robot or is off-site.)

Please note that default Media Mount Timeout is 0 (zero) - this means NO timeout. 
Please always take care when you change default settings - there has to be a good reason for changing it, as you run the risk of introducing problems with too low or too high values.
5 minutes for media mount timeout is certainly too low.