08-07-2013 03:27 AM
Hello Team
Source client for restore is : Windows Master server
Destination client for restore is Linux Server
when i restore single file then restore completed successfully but when i am trying to restore full folder then restore has been failed with below mentioned error
8/7/2013 4:05:22 PM - begin Restore
8/7/2013 4:05:24 PM - 1 images required
8/7/2013 4:05:24 PM - media GR1092 required
8/7/2013 4:05:58 PM - restoring image auviua0002_1375348779
8/7/2013 4:05:59 PM - Info bpbrm(pid=9204) auviua0002 is the host to restore to
8/7/2013 4:05:59 PM - Info bpbrm(pid=9204) telling media manager to start restore on client
8/7/2013 4:06:00 PM - Info bptm(pid=8340) Waiting for mount of media id GR1092 (copy 1) on server auvisb5500.
8/7/2013 4:06:00 PM - started process bptm (8340)
8/7/2013 4:06:00 PM - mounting GR1092
8/7/2013 4:06:00 PM - Info bptm(pid=8340) INF - Waiting for mount of media id GR1092 on server auvisb5500 for reading.
8/7/2013 4:06:00 PM - Info bpbrm(pid=4740) auviua0002 is the host to restore to
8/7/2013 4:06:00 PM - connecting
8/7/2013 4:06:00 PM - requesting resource GR1092
8/7/2013 4:06:00 PM - granted resource GR1092
8/7/2013 4:06:00 PM - granted resource HP.ULTRIUM4-SCSI.004
8/7/2013 4:06:02 PM - Info bpbrm(pid=4740) start tar32 on client
8/7/2013 4:06:02 PM - Info tar32(pid=1621) Restore started.
8/7/2013 4:06:02 PM - connected; connect time: 00:00:02
8/7/2013 4:07:06 PM - mounted; mount time: 00:01:06
8/7/2013 4:07:06 PM - Info bptm(pid=8340) GR1092
8/7/2013 4:07:06 PM - Info bptm(pid=8340) INF - Waiting for positioning of media id GR1092 on server auvisb5500 for reading.
8/7/2013 4:07:06 PM - positioning GR1092 to file 74
8/7/2013 4:07:52 PM - positioned GR1092; position time: 00:00:46
8/7/2013 4:07:52 PM - begin reading
8/7/2013 5:08:09 PM - Info bpbrm(pid=9204) child done, status 41
8/7/2013 5:08:09 PM - Info bpbrm(pid=9204) sending message to media manager: STOP RESTORE auviua0002_1375348779
8/7/2013 5:08:10 PM - Error bptm(pid=8336) The following files/folders were not restored:
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg.bck.gz
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg.def
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg.lg
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg.st
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg_add.st
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg_srv.pf
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mfg_usr.pf
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mlp.bck.gz
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mlp.def
8/7/2013 5:08:10 PM - Error bptm(pid=8336) UTF - /backup/backup4/inlive91/inlive91mlp.lg
8/7/2013 5:08:10 PM - Error bptm(pid=8336) more than 10 files were not restored, remaining ones are shown in the progress log.
8/7/2013 5:08:10 PM - Info bpbrm(pid=9204) media manager for backup id auviua0002_1375348779 exited with status 150: termination requested by administrator
8/7/2013 5:08:10 PM - restored image auviua0002_1375348779 - (network connection timed out(41)); restore time 01:02:12
8/7/2013 5:08:11 PM - end Restore; elapsed time: 01:02:49
invalid error number(2826)
Regards,
Davinder
08-07-2013 03:41 AM
You need the following logs to troubleshoot:
On media server: bptm and bpbrm
On client: tar
If the files to be restored are quite big, it may be a good idea to increase Client Read Timeout to a higher value. If timeout is the default of 300 (5 min), try 900.
Ensure above log folders exist before you attempt another restore.
If restore still fails with higher Client Read Timeout value, please copy log files to .txt files (e.g. bptm.txt) and post as File attachments.
08-07-2013 06:42 AM
08-07-2013 06:59 AM
The logs are quite big because of level 5 logging.
Please tell us what time was the last restore attempt and show all text in Details tab.
We need to see the tar log as well,
****EDIT ****
We REALLY need to see what happened on the client.
I can see in bptm log that the data was sent to the client:
23:02:35.744 [11920.11196] <2> wait_for_ready_socket: [2856] sent 48 directories/files to client auviua0002
tar log on client should tell us....
08-07-2013 07:00 AM
Hello Marianne.
Please find detail status below..
8/7/2013 9:19:56 PM - begin Restore
8/7/2013 9:19:58 PM - 1 images required
8/7/2013 9:19:58 PM - media GR1092 required
8/7/2013 9:20:32 PM - restoring image auviua0002_1375348779
8/7/2013 9:20:34 PM - Info bpbrm(pid=11276) auviua0002 is the host to restore to
8/7/2013 9:20:34 PM - Info bpbrm(pid=11276) telling media manager to start restore on client
8/7/2013 9:20:35 PM - Info bpbrm(pid=11712) auviua0002 is the host to restore to
8/7/2013 9:20:35 PM - connecting
8/7/2013 9:20:35 PM - requesting resource GR1092
8/7/2013 9:20:35 PM - awaiting resource GR1092 Reason: Drives are in use, Media Server: auvisb5500.hospira.corp,
Robot Number: 0, Robot Type: TLD, Media ID: N/A, Drive Name: N/A,
Volume Pool: N/A, Storage Unit: N/A, Drive Scan Host: N/A
8/7/2013 9:20:37 PM - Info bpbrm(pid=11712) start tar32 on client
8/7/2013 9:20:37 PM - Info tar32(pid=4609) Restore started.
8/7/2013 9:20:37 PM - connected; connect time: 00:00:02
8/7/2013 10:00:27 PM - Info bptm(pid=2856) Waiting for mount of media id GR1092 (copy 1) on server auvisb5500.
8/7/2013 10:00:27 PM - started process bptm (2856)
8/7/2013 10:00:27 PM - mounting GR1092
8/7/2013 10:00:27 PM - Info bptm(pid=2856) INF - Waiting for mount of media id GR1092 on server auvisb5500 for reading.
8/7/2013 10:00:27 PM - granted resource GR1092
8/7/2013 10:00:27 PM - granted resource HP.ULTRIUM4-SCSI.002
8/7/2013 10:01:32 PM - mounted; mount time: 00:01:05
8/7/2013 10:01:32 PM - Info bptm(pid=2856) GR1092
8/7/2013 10:01:32 PM - Info bptm(pid=2856) INF - Waiting for positioning of media id GR1092 on server auvisb5500 for reading.
8/7/2013 10:01:32 PM - positioning GR1092 to file 74
8/7/2013 10:02:16 PM - positioned GR1092; position time: 00:00:44
8/7/2013 10:02:16 PM - begin reading
8/7/2013 11:02:35 PM - Info bpbrm(pid=11276) child done, status 41
8/7/2013 11:02:35 PM - Info bpbrm(pid=11276) sending message to media manager: STOP RESTORE auviua0002_1375348779
8/7/2013 11:02:36 PM - Error bptm(pid=11920) The following files/folders were not restored:
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg.bck.gz
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg.def
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg.lg
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg.st
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg_add.st
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg_srv.pf
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mfg_usr.pf
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mlp.bck.gz
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mlp.def
8/7/2013 11:02:36 PM - Error bptm(pid=11920) UTF - /backup/backup4/inlive91/inlive91mlp.lg
8/7/2013 11:02:36 PM - Error bptm(pid=11920) more than 10 files were not restored, remaining ones are shown in the progress log.
8/7/2013 11:02:36 PM - Info bpbrm(pid=11276) media manager for backup id auviua0002_1375348779 exited with status 150: termination requested by administrator
8/7/2013 11:02:36 PM - restored image auviua0002_1375348779 - (network connection timed out(41)); restore time 01:42:04
8/7/2013 11:02:37 PM - Warning bprd(pid=10116) Restore must be resumed prior to first image expiration on 9/1/2013 7:19:39 PM
8/7/2013 11:02:37 PM - end Restore; elapsed time: 01:42:41
invalid error number(2826)
08-12-2013 05:07 AM
Hello Marianne.
Sorry for Delay, Please find TAR logs below..
[root@auviua0002 tar]# more log.081213
20:05:40 (161844.001) INF - TAR STARTED 31902
20:05:40 (161844.001) Setting network receive buffer size to 32032 bytes
20:07:34 (161844.001) CKP - 161844.001 1376302054 0 0 2 1 0 0 38 /backup/backup4/chqliv/chqempty.bck.gz
20:24:35 (161846.001) INF - TAR STARTED 32074
20:24:35 (161846.001) Setting network receive buffer size to 32032 bytes
20:27:48 (161846.001) CKP - 161846.001 1376303268 0 0 3 2 0 0 38 /backup/backup4/chqliv/chqempty.bck.gz
[root@auviua0002 tar]# more log.081013
02:49:16 (160931.002) INF - TAR STARTED 27640
02:49:16 (160931.002) Setting network receive buffer size to 32032 bytes
02:59:05 (160931.002) CKP - 160931.002 1376067545 0 0 2 1 0 0 36 /backup/backup4/inlive91/inlive91.pf
03:11:35 (161017.001) INF - TAR STARTED 27864
03:11:35 (161017.001) Setting network receive buffer size to 32032 bytes
03:12:33 (161017.001) CKP - 161017.001 1376068353 0 0 2 1 0 0 30 /backup/backup4/rpt/chqliv.tar
03:12:48 (161017.001) INF - TAR EXITING WITH STATUS = 0
03:12:48 (161017.001) INF - TAR RESTORED 9 OF 9 FILES SUCCESSFULLY
03:12:48 (161017.001) INF - TAR KEPT 0 EXISTING FILES
03:12:48 (161017.001) INF - TAR PARTIALLY RESTORED 0 FILES
03:26:45 (161018.001) INF - TAR STARTED 28019
03:26:45 (161018.001) Setting network receive buffer size to 32032 bytes
03:27:11 (161018.001) Write interrupted by SIGPIPE.
03:27:11 (161018.001) INF - TAR EXITING WITH STATUS = 40
03:27:11 (161018.001) INF - TAR RESTORED 0 OF 0 FILES SUCCESSFULLY
03:27:11 (161018.001) INF - TAR KEPT 0 EXISTING FILES
03:27:11 (161018.001) INF - TAR PARTIALLY RESTORED 0 FILES
03:30:46 (161019.001) INF - TAR STARTED 28040
03:30:46 (161019.001) Setting network receive buffer size to 32032 bytes
03:33:35 (161019.001) CKP - 161019.001 1376069615 0 0 2 1 0 0 36 /backup/backup4/nzlive91/nzlive91.pf
03:40:17 (161020.001) INF - TAR STARTED 28175
03:40:17 (161020.001) Setting network receive buffer size to 32032 bytes
03:43:04 (161020.001) CKP - 161020.001 1376070184 0 0 2 1 0 0 36 /backup/backup4/infalive/infalive.pf
03:47:46 (161021.001) INF - TAR STARTED 28843
03:47:46 (161021.001) Setting network receive buffer size to 32032 bytes
03:50:34 (161021.001) CKP - 161021.001 1376070634 0 0 2 1 0 0 36 /backup/backup4/inlive91/inlive91.pf
03:57:10 (161022.001) INF - TAR STARTED 28893
03:57:10 (161022.001) Setting network receive buffer size to 32032 bytes
04:05:31 (161022.001) CKP - 161022.001 1376071531 0 0 2 1 0 0 38 /backup/backup4/chqliv/chqempty.bck.gz
08-12-2013 05:46 AM
03:12:48 (161017.001) INF - TAR EXITING WITH STATUS = 0
03:12:48 (161017.001) INF - TAR RESTORED 9 OF 9 FILES SUCCESSFULLY
Here we see a successful restore.
03:27:11 (161018.001) Write interrupted by SIGPIPE.
03:27:11 (161018.001) INF - TAR EXITING WITH STATUS = 40
03:57:10 (161022.001) INF - TAR STARTED 2889303:57:10 (161022.001) Setting network receive buffer size to 32032 bytes
04:05:31 (161022.001) CKP - 161022.001 1376071531 0 0 2 1 0 0 38 /backup/backup4/chqliv/chqempty.bck.gz
This looks like a restore that is still in progress.
08-12-2013 06:25 AM
Hello Marianne.
This time i fired a restore of different date full backup, will let you know whether its failed or completed..
And will paste TAR logs once again ..
08-12-2013 06:32 AM
Hello Marianne.
But backup of this client completed successfully daily, no failure reported during backup , then why it shows network failure during restore??
08-12-2013 06:45 AM
Maybe you should ask your network team.
Restore data flow is going in opposite direction.