cancel
Showing results for 
Search instead for 
Did you mean: 

Restore failing with error 2850

Kunalgoel
Level 4

Hello Team,

Restore is failing with error code 2850. 

There are two sites Production site and DR site and only one master server. 

As per monthly activity, we took backup in prod site and offsiting the tapes at DR site.

Backup was taken through master server "NetbackupA" through TLD(6) robot and at DR site TLD(5) robot is there in same library and robot control host is media server "Media1"

So, i did restore failover from master server "NetbackupA" to media server "Media1" and initiate the restore and its getting failed with "Restore must be resumed prior to first image expiration".

 

Attached tar logs from media server

 

1 ACCEPTED SOLUTION

Accepted Solutions

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified
Something wrong with the way you typed Destination client name:

%20tmxdroradb1.thermaxindia.com

Did you by accident hit the spacebar before typing the hostname?

View solution in original post

17 REPLIES 17

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified
Can you please show all text in Job Details?

Hello Marianne,

Sorry for late reply. Please find attached detail status.

Hello Team,

Can anyone give suggestion on this

Hi All,

 

Tried again, getting below details status log

 

10/12/2019 16:59:36 - begin Restore
10/12/2019 16:59:37 - Info bprd (pid=62062704) Found (8,813) files in (1) images for Restore Job ID 45104.xxx
10/12/2019 16:59:37 - number of images required: 1
10/12/2019 16:59:37 - media needed: J216L5
10/12/2019 16:59:37 - media needed: 5087L5
10/12/2019 16:59:39 - restoring from image PROD_DB_BOOT_1570392000
10/12/2019 16:59:39 - restored from image PROD_DB_BOOT_1570392000; restore time: 0:00:00
10/12/2019 16:59:39 - Warning bprd (pid=62062704) Restore must be resumed prior to first image expiration on Sun Dec 8 01:30:00 2019
10/12/2019 16:59:39 - end Restore; elapsed time 0:00:03
Restore error (2850)

sdo
Moderator
Moderator
Partner    VIP    Certified

1) This warning "Restore must be resumed prior to first image expiration" can be ignored - all it is trying to say is that you have until so-and-so date to re-try the restore - i.e. the image(s) that you are restoring from begin to expire on that date.

.

2) You have shown us two different restores, first for image PROD_DB_BOOT_1570505476 requiring media J114L5 and 0003L5, and the second for image PROD_DB_BOOT_1570392000 requiring media J216L5 and 5087L5.

.

3) It looks like the first restore was manually aborted "exited with status 150: termination requested by administrator", but this could be NetBackup aborted the pending media mount "A pending request has been generated for this resource request." - but as to why NetBackup would only wait a minute, I do not know yet.

.

4) My question is, have you inventoried the robot(s) after unloading, and inventoried again after re-loading the required tape media?

Hello sdo,

I again tried the restore and getting same error.


10/12/2019 17:33:08 - begin Restore
10/12/2019 17:33:08 - Info bprd (pid=11469008) Found (8,813) files in (1) images for Restore Job ID 45105.xxx
10/12/2019 17:33:09 - number of images required: 1
10/12/2019 17:33:09 - media needed: J216L5
10/12/2019 17:33:09 - media needed: 5087L5
10/12/2019 17:33:11 - restoring from image PROD_DB_BOOT_1570392000
10/12/2019 17:33:11 - restored from image PROD_DB_BOOT_1570392000; restore time: 0:00:00
10/12/2019 17:33:11 - Warning bprd (pid=11469008) Restore must be resumed prior to first image expiration on Sun Dec 8 01:30:00 2019
10/12/2019 17:33:11 - end Restore; elapsed time 0:00:03
Restore error (2850)

Attached bpcd and bpbrm logs.

I found below in bpbrm logs:

17:25:41.499 [42008632.1] <2> ConnectToBPCD: bpcd_connect_and_verify(tmxdroradb1.thermaxindia.com, tmxdroradb1.thermaxindia.com) failed: 48
17:25:41.499 [42008632.1] <16> bpbrm start_bpcd_stat: connection refused to host tmxdroradb1.thermaxindia.com

17:25:41.585 [42008632.1] <32> bpbrm multiplexed_restore: could not set non-blocking I/O on media socket, A file descriptor does not refer to an open file. (9)

Hello,

 

Attached bpbrm with verbose 5

Hello,

BPTM logs not generated much

 

ash-3.2# cat root.101219_00001.log
18:04:41.805 [25297174] <2> SetMaxDataLimit: maximum data size: current=9223372036854775807 max=9223372036854775807
18:04:41.813 [25297174] <2> initialize: fd values STDOUTSOCK=4 STDERRSOCK=6
18:04:41.817 [25297174] <2> bptm: INITIATING (VERBOSE = 5): -rptdrv -jobid -1570874613 -jm
18:04:41.817 [25297174] <2> bptm: PORT_STATUS = 0x00000000
18:04:41.831 [25297174] <2> main: Sending [EXIT STATUS 0] to NBJM
18:04:41.831 [25297174] <2> bptm: EXITING with status 0 <----------

Yes, we have inventoried the robot

Hello All,

Media server and clien is same

Connectivity is perfect from Master to media/client and Media/client to master. Below is the output from Media/client to master:

ash-3.2# ping NetbackupA
PING NetbackupA.thermaxdomain.com: (10.100.1.235): 56 data bytes
64 bytes from 10.100.1.235: icmp_seq=0 ttl=252 time=25 ms
64 bytes from 10.100.1.235: icmp_seq=1 ttl=252 time=24 ms
64 bytes from 10.100.1.235: icmp_seq=2 ttl=252 time=24 ms
64 bytes from 10.100.1.235: icmp_seq=3 ttl=252 time=24 ms
64 bytes from 10.100.1.235: icmp_seq=4 ttl=252 time=24 ms

--- NetbackupA.thermaxdomain.com ping statistics ---
5 packets transmitted, 5 packets received, 0% packet loss
round-trip min/avg/max = 24/24/25

bash-3.2# telnet NetbackupA 13782
Trying...
Connected to NetbackupA.thermaxdomain.com.
Escape character is '^]'.


bash-3.2# telnet NetbackupA 1556
Trying...
Connected to NetbackupA.thermaxdomain.com.
Escape character is '^]'.


bash-3.2#
bash-3.2# telnet NetbackupA 13724
Trying...
Connected to NetbackupA.thermaxdomain.com.
Escape character is '^]'.

ash-3.2# ./bpclntcmd -pn
expecting response from server NetbackupA.thermaxdomain.com
tmxdroradb1.thermaxindia.com tmxdroradb1.thermaxindia.com 10.111.1.196 35024

bash-3.2# ./bpclntcmd -hn NetbackupA
host NetbackupA: NetbackupA.thermaxdomain.com at 10.100.1.235
aliases: NetbackupA.thermaxdomain.com NetbackupA 10.100.1.235

bash-3.2# ./bpclntcmd -ip 10.100.1.235
host 10.100.1.235: NetbackupA.thermaxdomain.com at 10.100.1.235
aliases: NetbackupA.thermaxdomain.com 10.100.1.235

ash-3.2# ./bptestbpcd -client NetbackupA -verbose
1 1 1
10.111.1.196:35048 -> 10.100.1.235:1556
10.111.1.196:35049 -> 10.100.1.235:1556
PEER_NAME = tmxdroradb1.thermaxindia.com
HOST_NAME = NetbackupA
CLIENT_NAME = NetbackupA
VERSION = 0x07720000
PLATFORM = rs6000_61
PATCH_VERSION = 7.7.2.0
SERVER_PATCH_VERSION = 7.7.2.0
MASTER_SERVER = NetbackupA
EMM_SERVER = NetbackupA
NB_MACHINE_TYPE = MASTER_SERVER
10.111.1.196:35051 -> 10.100.1.235:1556

 

Connectivity from master to media/client:

ash-3.2# ping tmxdroradb1.thermaxindia.com
PING tmxdroradb1.thermaxindia.com: (10.111.1.196): 56 data bytes
64 bytes from 10.111.1.196: icmp_seq=0 ttl=251 time=24 ms
64 bytes from 10.111.1.196: icmp_seq=1 ttl=251 time=24 ms
64 bytes from 10.111.1.196: icmp_seq=2 ttl=251 time=24 ms
64 bytes from 10.111.1.196: icmp_seq=3 ttl=251 time=24 ms
64 bytes from 10.111.1.196: icmp_seq=4 ttl=251 time=36 ms

--- tmxdroradb1.thermaxindia.com ping statistics ---
5 packets transmitted, 5 packets received, 0% packet loss
round-trip min/avg/max = 24/26/36 ms


bash-3.2# telnet tmxdroradb1.thermaxindia.com 13782
Trying...
Connected to tmxdroradb1.thermaxindia.com.
Escape character is '^]'.


bash-3.2# telnet tmxdroradb1.thermaxindia.com 1556
Trying...
Connected to tmxdroradb1.thermaxindia.com.
Escape character is '^]'.


bash-3.2# telnet tmxdroradb1.thermaxindia.com 13724
Trying...
Connected to tmxdroradb1.thermaxindia.com.
Escape character is '^]'.

ash-3.2# ./bpclntcmd -hn tmxdroradb1.thermaxindia.com
host tmxdroradb1.thermaxindia.com: tmxdroradb1.thermaxindia.com at 10.111.1.196
aliases: tmxdroradb1.thermaxindia.com 10.111.1.196


bash-3.2# ./bpclntcmd -ip 10.111.1.196
host 10.111.1.196: tmxdroradb1.thermaxindia.com at 10.111.1.196
aliases: tmxdroradb1.thermaxindia.com 10.111.1.196

ash-3.2# ./bptestbpcd -client tmxdroradb1.thermaxindia.com -verbose -debug
18:52:05.770 [62062814] <2> bptestbpcd: VERBOSE = 0
18:52:05.770 [62062814] <2> read_client: dname=., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
18:52:05.770 [62062814] <2> read_client: dname=.., offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
18:52:05.770 [62062814] <2> read_client: dname=CO_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
18:52:05.770 [62062814] <2> read_client: dname=OA_0, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
18:52:05.770 [62062814] <2> read_client: dname=host_info, offline=0, online_at=0 offline_at=0 offlineres=0 onlineres_at=0 offlineres_at=0
18:52:05.773 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1691] in failed file cache ERR=8 NAME=CHNFILESRV.Thermaxdomain.com SVC=NULL
18:52:05.773 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:05.827 [62062814] <2> vnet_pbxConnect: pbxConnectEx Succeeded
18:52:05.827 [62062814] <2> logconnections: BPCD CONNECT FROM 10.100.1.235.24416 TO 10.111.1.196.1556 fd = 4
18:52:05.827 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1637] in failed cache ERR=8 NAME=CHNFILESRV.Thermaxdomain.com SVC=NULL
18:52:05.827 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:05.879 [62062814] <2> vnet_pbxConnect: pbxConnectEx Succeeded
18:52:05.907 [62062814] <8> do_pbx_service: [vnet_connect.c:2227] via PBX VNETD CONNECT FROM 10.100.1.235.24417 TO 10.111.1.196.1556 fd = 5
18:52:05.907 [62062814] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:440] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
18:52:05.960 [62062814] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:457] ipc_string /usr/openv/var/tmp/vnet-18216570886076315330000000388-nKwMge
18:52:06.059 [62062814] <2> bpcr_get_version_rqst: bpcd version: 07720000
1 1 1
10.100.1.235:24416 -> 10.111.1.196:1556
10.100.1.235:24417 -> 10.111.1.196:1556
18:52:06.089 [62062814] <2> bpcr_get_peername_rqst: Server peername length = 28
18:52:06.142 [62062814] <2> bpcr_get_hostname_rqst: Server hostname length = 9
18:52:06.191 [62062814] <2> bpcr_get_clientname_rqst: Server clientname length = 28
18:52:06.240 [62062814] <2> bpcr_get_version_rqst: bpcd version: 07720000
18:52:06.269 [62062814] <2> bpcr_get_platform_rqst: Server platform length = 9
18:52:06.318 [62062814] <2> bpcr_get_version_rqst: bpcd version: 07720000
18:52:06.368 [62062814] <2> bpcr_patch_version_rqst: theRest == > <
18:52:06.393 [62062814] <2> bpcr_get_version_rqst: bpcd version: 07720000
18:52:06.442 [62062814] <2> bpcr_patch_version_rqst: theRest == > <
18:52:06.467 [62062814] <2> bpcr_get_version_rqst: bpcd version: 07720000
18:52:06.529 [62062814] <8> retry_getaddrinfo_for_real: [vnet_addrinfo.c:1082] getaddrinfo() failed RV=8 NAME=tmxoradb1 SVC=0 errno=0
18:52:06.529 [62062814] <8> retry_getaddrinfo: [vnet_addrinfo.c:922] retry_getaddrinfo_for_real failed RV=8 NAME=tmxoradb1 SVC=0
18:52:06.529 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1732] retry_getaddrinfo() failed RV=8 NAME=tmxoradb1 SVC=NULL
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:06.531 [62062814] <8> vnet_same_host_and_update: [vnet_addrinfo.c:2971] vnet_cached_getaddrinfo() failed STAT=6 RV=8 NAME1=tmxoradb1
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1637] in failed cache ERR=8 NAME=tmxoradb1 SVC=NULL
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:06.531 [62062814] <8> vnet_same_host_and_update: [vnet_addrinfo.c:2971] vnet_cached_getaddrinfo() failed STAT=6 RV=8 NAME1=tmxoradb1
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1637] in failed cache ERR=8 NAME=tmxoradb1 SVC=NULL
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:06.531 [62062814] <8> vnet_same_host_and_update: [vnet_addrinfo.c:2971] vnet_cached_getaddrinfo() failed STAT=6 RV=8 NAME1=tmxoradb1
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1637] in failed cache ERR=8 NAME=tmxoradb1 SVC=NULL
18:52:06.531 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:06.531 [62062814] <8> vnet_same_host_and_update: [vnet_addrinfo.c:2971] vnet_cached_getaddrinfo() failed STAT=6 RV=8 NAME1=tmxoradb1
PEER_NAME = NetbackupA.thermaxdomain.com
HOST_NAME = tmxoradb1
CLIENT_NAME = tmxdroradb1.thermaxindia.com
VERSION = 0x07720000
PLATFORM = rs6000_61
PATCH_VERSION = 7.7.2.0
SERVER_PATCH_VERSION = 7.7.2.0
MASTER_SERVER = NetbackupA.thermaxdomain.com
EMM_SERVER = NetbackupA
NB_MACHINE_TYPE = CLIENT
18:52:06.532 [62062814] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1637] in failed cache ERR=8 NAME=CHNFILESRV.Thermaxdomain.com SVC=NULL
18:52:06.532 [62062814] <8> vnet_cached_getaddrinfo: [vnet_addrinfo.c:1360] vnet_cached_getaddrinfo_and_update() failed 6 0x6
18:52:06.581 [62062814] <2> vnet_pbxConnect: pbxConnectEx Succeeded
18:52:06.606 [62062814] <8> do_pbx_service: [vnet_connect.c:2227] via PBX VNETD CONNECT FROM 10.100.1.235.24418 TO 10.111.1.196.1556 fd = 6
18:52:06.606 [62062814] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:440] VN_REQUEST_CONNECT_FORWARD_SOCKET 10 0xa
18:52:06.657 [62062814] <8> vnet_vnetd_connect_forward_socket_begin: [vnet_vnetd.c:457] ipc_string /usr/openv/var/tmp/vnet-16664570886077014197000000388-shz7ge
10.100.1.235:24418 -> 10.111.1.196:1556
<2>bptestbpcd: EXIT status = 0
18:52:06.736 [62062814] <2> bptestbpcd: EXIT status = 0
bash-3.2#

Hello All,

Attached bprd with verbose 5.

Please assist on this

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@Kunalgoel 

The logs do not match.

I first had a look at bprd log for details about the initial setup of the restore job.

I was looking at the restore job that was started at 18:59 for image-id PROD_DB_BOOT_1570392000.
(Your bprd log starts at 18:57)

 I then wanted to see what is happening next in bpbrm.
The bpbrm log that you uploaded ends at 17:56:38 and contains no info of restore attempt for this image.

You need to give us a set of matching logs, please:
Job details, bprd and bpbrm. All for the same restore attempt.

For troubleshooting on VOX, level 3 logs are fine.
When you log a Support call with Veritas, level 5 logs will be needed. 

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

@Kunalgoel 

Looking at this post on Saturday, it seems that that you have found the problem:


@Kunalgoel wrote:

Hello sdo,

I again tried the restore and getting same error.


10/12/2019 17:33:08 - begin Restore
10/12/2019 17:33:08 - Info bprd (pid=11469008) Found (8,813) files in (1) images for Restore Job ID 45105.xxx
10/12/2019 17:33:09 - number of images required: 1
10/12/2019 17:33:09 - media needed: J216L5
10/12/2019 17:33:09 - media needed: 5087L5
10/12/2019 17:33:11 - restoring from image PROD_DB_BOOT_1570392000
10/12/2019 17:33:11 - restored from image PROD_DB_BOOT_1570392000; restore time: 0:00:00
10/12/2019 17:33:11 - Warning bprd (pid=11469008) Restore must be resumed prior to first image expiration on Sun Dec 8 01:30:00 2019
10/12/2019 17:33:11 - end Restore; elapsed time 0:00:03
Restore error (2850)

Attached bpcd and bpbrm logs.

I found below in bpbrm logs:

17:25:41.499 [42008632.1] <2> ConnectToBPCD: bpcd_connect_and_verify(tmxdroradb1.thermaxindia.com, tmxdroradb1.thermaxindia.com) failed: 48
17:25:41.499 [42008632.1] <16> bpbrm start_bpcd_stat: connection refused to host tmxdroradb1.thermaxindia.com

17:25:41.585 [42008632.1] <32> bpbrm multiplexed_restore: could not set non-blocking I/O on media socket, A file descriptor does not refer to an open file. (9)



The media server cannot connect to itself as client. 

Do you have a SERVER entry for itself on the media server? 
Can you show us bp.conf on the media server?

Have you ever tried to do a small backup of a folder on the media server? 

Do the bptestbpcd on the media server to test connectivity to itself :
bptestbpcd -client tmxdroradb1.thermaxindia.com -verbose -debug

Hello Marianne,

That restore completed.

But now i am initiated restore with same source client restore and destination client of restore and its failing with 48.

 

10/14/2019 21:39:11 - Error bpbrm (pid=28836112) bpcd on %20tmxdroradb1.thermaxindia.com exited with status 48: client hostname could not be found10/14/2019 21:39:12 - Info bpbrm (pid=28836112) telling media manager to start restore on client10/14/2019 21:39:12 - Info bpbrm (pid=28836112) spawning a brm child process10/14/2019 21:39:12 - Info bpbrm (pid=28836112) child pid: 1527009810/14/2019 21:39:12 - connecting10/14/2019 21:39:13 - Error bpbrm (pid=15270098) bpcd on %20tmxdroradb1.thermaxindia.com exited with status 48: client hostname could not be found10/14/2019 21:39:13 - Error bpbrm (pid=15270098) cannot put rename file on %20tmxdroradb1.thermaxindia.com10/14/2019 21:39:13 - Info bpbrm (pid=28836112) sending message to media manager: STOP RESTORE PROD_DB_BOOT_157050547610/14/2019 21:39:13 - Info bpbrm (pid=28836112) media manager for backup id PROD_DB_BOOT_1570505476 exited with status 150: termination requested by administrator10/14/2019 21:46:37 - begin Restore10/14/2019 21:46:37 - Info bprd (pid=62914670) Found (8,674) files in (1) images for Restore Job ID 45185.xxx10/14/2019 21:46:37 - number of images required: 110/14/2019 21:46:37 - media needed: J114L510/14/2019 21:46:37 - media needed: 0003L510/14/2019 21:46:40 - restoring from image PROD_DB_BOOT_157050547610/14/2019 21:46:43 - requesting resource J114L510/14/2019 21:46:43 - granted resource  J114L510/14/2019 21:46:43 - granted resource  IBM.ULT3580-TD5.00410/14/2019 21:46:43 - restored from image PROD_DB_BOOT_1570505476; restore time: 0:00:0310/14/2019 21:46:44 - Warning bprd (pid=62914670) Restore must be resumed prior to first image expiration on Tue Oct 22 09:01:16 IST 201910/14/2019 21:46:44 - end Restore; elapsed time 0:00:07Restore error  (2850)

 

sdo
Moderator
Moderator
Partner    VIP    Certified

show us the bp.conf from tmxdroradb1.thermaxindia.com

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified
Something wrong with the way you typed Destination client name:

%20tmxdroradb1.thermaxindia.com

Did you by accident hit the spacebar before typing the hostname?

sdo
Moderator
Moderator
Partner    VIP    Certified

Why didn't you answer @Marianne 's questions?

@Marianne is an acknowledged expert!  When Marianne asks you to do something, then you really should take the time to answer properly.

The reason any of us are ever asked to do something by Marianne may not always be immediately obvious to us, but that's actually because we are not experts, whereas Marianne is.  Yes, I do do as requested too.  I know that I don't know as much.  The quickest way to reach a solution, or final advice is to answer completely and clearly.

Thank you Marianne.

Yeah, it was typo error. Thank u for your help.

Sorry for late Reply as i was not in office.