07-18-2008 08:07 AM
Hi all,
I am developing NDMP server that will support Veritas NetBackup LOCAL backup. NetBackup is version 6.5 and it is running on Windows.
The backup part is currently stabe and running but I came accross a problem that I can not solve while restoring....
The error code says something about no entity found ...
7/18/2008 2:24:29 PM - begin Restore
7/18/2008 2:24:30 PM - media A00003 required
7/18/2008 2:24:30 PM - restoring image node0_1216383756
7/18/2008 2:24:30 PM - connecting
7/18/2008 2:24:30 PM - connected; connect time: 00:00:00
7/18/2008 2:24:31 PM - started process bptm (5148)
7/18/2008 2:24:33 PM - started process bptm (5148)
7/18/2008 2:24:33 PM - mounting A00003
7/18/2008 2:24:36 PM - mounted; mount time: 00:00:03
7/18/2008 2:24:36 PM - positioning A00003 to file 1
7/18/2008 2:24:36 PM - positioned A00003; position time: 00:00:00
7/18/2008 2:24:36 PM - begin reading
7/18/2008 2:24:36 PM - Error ndmpagent(pid=5460) unexpected return value from db_FLISTreceive: 227
7/18/2008 2:24:36 PM - Error ndmpagent(pid=5460) NDMP restore failed from path UNKNOWN
7/18/2008 2:24:31 PM - requesting resource A00003
7/18/2008 2:24:31 PM - granted resource A00003
7/18/2008 2:24:31 PM - granted resource ST4
7/18/2008 2:24:42 PM - Error bpbrm(pid=5464) socket read failed, An existing connection was forcibly closed by the remote host. (10054)
7/18/2008 2:24:42 PM - restored image node0_1216383756 - (file read failed(13)); restore time 00:00:12
7/18/2008 2:24:43 PM - end Restore; elapsed time: 00:00:14
the restore failed to recover the requested files(5)
7/18/2008 2:24:47 PM - Error bpbrm(pid=5464) client restore EXIT STATUS 13: file read failed
Below are the debugs from bpbrm.log
16:03:14.656 [1284.3096] <2> bpbrm spawn_child: "c:\Program Files\Veritas\NetBackup\bin\bptm.exe" -r -pid 1284 -c 10.43.1.10 -cl test -bt 1216212590 -b 10.43.1.10_1216212590 -st 0 -mud 180 -hostname 10.43.1.10 -L /C/Programà€ Files/Veritas/NetBackup/logs/user_ops/Admin000/logs/NBWIN037 -ru root -rclnt r2 -rclnthostname r2.hermes.si -firstblk 0 -restoreid 149.001 -ct 19 -pid 1284 -v -lcmsg en -lctime en -no_callback -connect_options 0x01010100 -jobid 149 -masterversion 650000 -S r2 -ndmpport 49572
16:03:14.656 [1284.3096] <2> bpbrm create_mm_terminate: created terminate event pid 4960
16:03:14.656 [1284.3096] <2> bpbrm create_mm_suspend: created suspend event pid 4960
16:03:18.421 [1284.3096] <2> bpbrm mm_sig: received ready signal from media manager
16:03:24.515 [1284.3096] <2> bpbrm main: client 10.43.1.10 EXIT STATUS = 227: no entity was found
16:03:24.515 [1284.3096] <2> bpbrm main: client 10.43.1.10 EXIT STATUS = 227: no entity was found
16:03:24.515 [1284.3096] <2> bpbrm wait_for_child: start
16:03:24.625 [1284.3096] <2> bpbrm wait_for_child: child exit_status = 5
16:03:24.625 [1284.3096] <2> signal_ndmpagent: sending signal=1 to ndmpagent on r2, client_pid=2056
16:03:24.625 [1284.3096] <2> bpcr_send_signal: Ignoring connect_opts = 0x01030202
16:03:24.625 [1284.3096] <2> read_client: ?
16:03:24.625 [1284.3096] <2> read_client: opendir() failed: r2: No such file or directory (2)
16:03:24.625 [1284.3096] <2> ConnectToBPCD: db_getCLIENT(r2) failed: 227
16:03:24.625 [1284.3096] <2> hosts_equal: Comparing hosts <r2> and <r2>
16:03:24.625 [1284.3096] <2> hosts_equal: names are the same
16:03:24.625 [1284.3096] <2> local_bpcr_connect: bpcr.c.274: connect_opts = 0x01000100 connect_opts2 = 0x01000100
16:03:24.625 [1284.3096] <2> local_bpcr_connect: bpcr.c.281: connect_opts = 0x01000100
16:03:24.625 [1284.3096] <2> local_bpcr_connect: bpcr.c.320: daemon_port_type = 0
16:03:24.625 [1284.3096] <2> vnet_async_connect: vnet_vnetd.c.3983: connect in progress: 0 0x00000000
16:03:24.656 [1284.3096] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
16:03:24.656 [1284.3096] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd
16:03:24.656 [1284.3096] <2> vnet_async_connect: vnet_vnetd.c.4169: in progress connect: 0 0x00000000
16:03:24.656 [1284.3096] <2> vnet_async_connect: vnet_vnetd.c.4172: connect: async CONNECT FROM 10.43.1.33.49650 TO 10.43.1.33.13724 fd = 1608
16:03:24.656 [1284.3096] <2> logconnections: BPCD CONNECT FROM 10.43.1.33.49650 TO 10.43.1.33.13724
16:03:24.656 [1284.3096] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required
16:03:24.656 [1284.3096] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required
16:03:24.656 [1284.3096] <2> bpcr_authenticate_connection: no authentication required
16:03:24.656 [1284.3096] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 10.43.1.33.49651 TO 10.43.1.33.13724 fd = 1612
16:03:24.687 [1284.3096] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
16:03:24.687 [1284.3096] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 49652
16:03:24.687 [1284.3096] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.560: hash_str1: f8036e2fecf2bb96355bb069600112ae
16:03:24.734 [1284.3096] <2> bpcr_send_signal: CLIENT_CMD_SOCK from bpcr = 1608
16:03:24.734 [1284.3096] <2> bpcr_send_signal: CLIENT_STAT_SOCK from bpcr = 1612
16:03:24.734 [1284.3096] <16> bpbrm readline: socket read failed, An existing connection was forcibly closed by the remote host. (10054)
16:03:24.734 [1284.3096] <2> set_job_details: Sending Tfile jobid (149)
16:03:24.734 [1284.3096] <2> set_job_details: LOG 1216217004 16 bpbrm 1284 socket read failed, An existing connection was forcibly closed by the remote host. (10054)
16:03:24.734 [1284.3096] <2> set_job_details: Done
16:03:24.734 [1284.3096] <2> db_error_add_to_file: dberrorq.c:midnite = 1216159200
16:03:24.734 [1284.3096] <2> bpbrm kill_child_process_Ex: start
16:03:29.734 [1284.3096] <16> bpbrm Exit: client restore EXIT STATUS 13: file read failed
16:03:29.734 [1284.3096] <2> set_job_details: Sending Tfile jobid (149)
16:03:29.734 [1284.3096] <2> set_job_details: LOG 1216217009 16 bpbrm 1284 client restore EXIT STATUS 13: file read failed
16:03:29.734 [1284.3096] <2> set_job_details: Done
Can somebody help???
07-18-2008 12:15 PM
16:03:24.734 [1284.3096] <16> bpbrm readline: socket read failed, An existing connection was forcibly closed by the remote host. (10054)
That looks like a network issue, maybe. Do you have a bpcd log?
07-20-2008 12:29 PM
have you configure your media server with NDMP drives who will have access to that filer? you can confirm with the following:
List Attributes
07-21-2008 06:25 AM
07-22-2008 06:41 AM
Any way I used Wireshark to check if it is due to a Network problem, but the fact that NDMP_CONNECT_CLOSE is issued says it is not. It something with the internal database of Netbackup.
What does mean "No entity found".
Can someone help?
Regards,
Gorjan
07-22-2008 10:06 AM
>What does mean "No entity found".
It means it was expecting some information and it didn't get it. I notice your client's hostname is an IP address - that's probably not the problem, but if it ever had a hostname, that might explain why NetBackup would not be getting back any information (if it's looking in the wrong place).
Here's another "no entity found" (status code 227) from your bpbrm log:
16:03:24.625 [1284.3096] <2> read_client: opendir() failed: r2: No such file or directory (2)
16:03:24.625 [1284.3096] <2> ConnectToBPCD: db_getCLIENT(r2) failed: 227
Looks like "r2" is r2.hermes.si...your server? (Seeing the short AND fully-qualified hostname makes me uneasy as well, but I'm not sure if that is contributing to your issue here or not.)
You will probably want to open a case with support. Have these logs ready for your TSE to examine:
bpbrm
bpcd
bptm
ndmpagent
07-22-2008 02:14 PM
Speaking from an experienced NDMP user, Symantec has had horrible issues with NDMP support and special characters. I haven’t seen many issues with backups of data on my end, but I have never configured a backup in the method you are doing. Our problems have been with restores. It can be a nightmare on occasion. Especially redirected restores with special characters or spaces in the redirected path.
This could be a symptom of that. I would open a support case to get it resolved.