On the weekend , our DBA restored some oracle backups (RMAN) and according to
him the restore was deadly slow. I am attaching the log. It shows the transfer
rate is around 7 000 k/sec , normal as we are using SUn l280 (dlt 7000) .
Operating System is solaris 2.6 with netbackup 3.1.1. No network as the drive
is attached with the DB server and the same machine is acting a master server.
I have checked the log. It shows that there is kind of loop , after every 5 min
, it shows that restore started and then is secessful. Any explanation.
thanks in advance
Atif
------------------------------------------------------------------------
00:50:31 [6610] <4> get_init_info: INF - verbose=<1>
00:50:31 [6610] <2> getsockconnected: host=vghprd service=bprd
address=142.71.105.1 protocol=tcp non-reserved port=13720
00:50:31 [6610] <4> sbtopen: R - db=FSPROD, tbs=>
bfs=<FSPROD_t454478486_s1379_p10> <>
00:50:31 [6610] <4> setup_cmd: /usr/openv/netbackup/bin/bprestore -I -s
12/25/95 16:00:00 -e 02/23/02 00:50:31 -L /var/tmp/obk_NAA0RIXde -t 4
/FSPROD_t454478486_s1379_p10
00:50:32 [6610] <4> start_server: restore was successfully initiated.
00:50:32 [6610] <4> do_init: initial client_read_timeout = 3600
00:50:32 [6610] <4> do_init: <Restore started Sat Feb 23 00:50:31 2002>
00:50:42 [6610] <4> do_init: <00:50:39 (8162.xxx) Restore job id 8162 will
require 1 image.>
00:50:42 [6610] <4> do_init: <00:50:39 (8162.xxx) Media id PRD415 is needed for
the restore.>
00:50:47 [6610] <4> do_init: <00:50:46 (8162.001) Restoring from image created
Fri Feb 22 05:04:07 2002>
00:50:47 [6610] <4> do_init: <00:50:46 (8162.001) INF - Data socket =
vghprd.4996>
00:50:48 [6610] <4> do_init: <00:50:46 (8162.001) INF - Name socket =
vghprd.4995>
00:50:49 [6610] <4> do_init: <00:50:46 (8162.001) INF - New data socket =
vghprd.0>
00:50:49 [6610] <4> do_init: <00:50:46 (8162.001) INF - Use shared memory = 1>
00:50:49 [6610] <4> do_init: <00:50:46 (8162.001) INF - Restore id = 8162.001>
00:50:49 [6610] <4> do_init: <00:50:46 (8162.001) INF - Client read timeout =
900>
00:50:49 [6610] <4> do_init: <00:50:46 (8162.001) INF - Media mount timeout = 0>
00:50:49 [6610] <4> do_init: <00:50:48 (8162.001) INF - Waiting for positioning
of media id PRD415 on server vghprd.>
00:50:49 [6610] <4> do_init: <00:50:49 (8162.001) INF - Beginning restore from
server vghprd to client vghprd.>
00:50:51 [6610] <2> getsockconnected: host=vghprd service=bprd
address=142.71.105.1 protocol=tcp non-reserved port=4998
00:50:51 [6610] <2> get_next_file: [17130] received string: (1 0 1073741824 1 0
1 1073741824 /FSPROD_t454478486_s1379_p10)
00:50:51 [6610] <4> do_restore: Close data socket 22. use shared mem
00:50:51 [6610] <4> do_restore: FSPROD_t454478486_s1379_p10 <>: 1,073,741,824
bytes+ 1 GB
00:50:51 [6610] <4> sbtopen: R - Startup took 20 secs. Transfering data ...
00:50:51 [6610] <4> sbtread: reading buf # 1.
00:55:13 [6610] <4> detach_shm: [17130] setting tar_exitstat = 0
00:55:13 [6610] <4> close_connection: <INF - EXIT STATUS = 0> sent to server.
00:55:18 [6610] <4> read_exit_status: <00:55:14 (8162.001) Status of restore
from image created Fri Feb 22 05:04:07 2002 = the requested operation was
successfully completed>
00:55:18 [6610] <4> read_exit_status: <>
00:55:18 [6610] <4> read_exit_status: <00:55:16 INF - Server status = 0>
00:55:18 [6610] <4> read_exit_status: <00:55:16 (8162.xxx) INF - Status = the
requested operation was successfully completed.>
00:55:18 [6610] <4> sbtclose: FSPROD_t454478486_s1379_p10 <> restored.
1,073,741,824 bytes + 1 GB.
00:55:18 [6610] <4> sbtclose: R - (1073742336) 32768 bufs in 287 secs ==>
7307K/sec Sat Feb 23 00:55:18 2002
00:55:26 [6610] <4> get_init_info: INF - verbose=<1>
00:55:26 [6610] <2> getsockconnected: host=vghprd service=bprd
address=142.71.105.1 protocol=tcp non-reserved port=13720
00:55:26 [6610] <4> sbtopen: R - db=FSPROD, tbs=>
bfs=<FSPROD_t454478486_s1379_p11> <>
00:55:26 [6610] <4> setup_cmd: /usr/openv/netbackup/bin/bprestore -I -s
12/25/95 16:00:00 -e 02/23/02 00:55:26 -L /var/tmp/obk_OAA0L.1iU -t 4
/FSPROD_t454478486_s1379_p11
00:55:27 [6610] <4> start_server: restore was successfully initiated.
00:55:27 [6610] <4> do_init: initial client_read_timeout = 3600
00:55:27 [6610] <4> do_init: <Restore started Sat Feb 23 00:55:26 2002>
00:55:32 [6610] <4> do_init: <00:55:29 (8163.xxx) Restore job id 8163 will
require 1 image.>
00:55:32 [6610] <4> do_init: <00:55:29 (8163.xxx) Media id PRD415 is needed for
the restore.>
00:55:37 [6610] <4> do_init: <00:55:36 (8163.001) Restoring from image created
Fri Feb 22 05:10:43 2002>
00:55:37 [6610] <4> do_init: <00:55:36 (8163.001) INF - Data socket =
vghprd.4996>
00:55:38 [6610] <4> do_init: <00:55:36 (8163.001) INF - Name socket =
vghprd.4995>
00:55:39 [6610] <4> do_init: <00:55:36 (8163.001) INF - New data socket =
vghprd.0>
00:55:39 [6610] <4> do_init: <00:55:36 (8163.001) INF - Use shared memory = 1>
00:55:39 [6610] <4> do_init: <00:55:36 (8163.001) INF - Restore id = 8163.001>
00:55:39 [6610] <4> do_init: <00:55:36 (8163.001) INF - Client read timeout =
900>
00:55:39 [6610] <4> do_init: <00:55:36 (8163.001) INF - Media mount timeout = 0>
00:55:39 [6610] <4> do_init: <00:55:38 (8163.001) INF - Waiting for positioning
of media id PRD415 on server vghprd.>
00:55:44 [6610] <4> do_init: <00:55:39 (8163.001) INF - Beginning restore from
server vghprd to client vghprd.>
00:55:46 [6610] <2> getsockconnected: host=vghprd service=bprd
address=142.71.105.1 protocol=tcp non-reserved port=5000
00:55:46 [6610] <2> get_next_file: [17550] received string: (1 0 1073741824 1 0
1 1073741824 /FSPROD_t454478486_s1379_p11)
00:55:46 [6610] <4> do_restore: Close data socket 22. use shared mem
00:55:46 [6610] <4> do_restore: FSPROD_t454478486_s1379_p11 <>: 1,073,741,824
bytes+ 1 GB
00:55:46 [6610] <4> sbtopen: R - Startup took 20 secs. Transfering data ...
00:55:46 [6610] <4> sbtread: reading buf # 1.
01:00:15 [6610] <4> detach_shm: [17550] setting tar_exitstat = 0
01:00:15 [6610] <4> close_connection: <INF - EXIT STATUS = 0> sent to server.
01:00:20 [6610] <4> read_exit_status: <01:00:17 (8163.001) Status of restore
from image created Fri Feb 22 05:10:43 2002 = the requested operation was
successfully completed>
01:00:20 [6610] <4> read_exit_status: <>
01:00:20 [6610] <4> read_exit_status: <01:00:18 INF - Server status = 0>
01:00:20 [6610] <4> read_exit_status: <01:00:18 (8163.xxx) INF - Status = the
requested operation was successfully completed.>
01:00:20 [6610] <4> sbtclose: FSPROD_t454478486_s1379_p11 <> restored.
1,073,741,824 bytes + 1 GB.
01:00:20 [6610] <4> sbtclose: R - (1073742336) 32768 bufs in 294 secs ==>
7133K/sec Sat Feb 23 01:00:20 2002
|
