Netbackup Tape import Phase 2 fails in error 191

[Dhaarani]

Someone please provide q quick resolution for the below issue. We tried to import from an expired tape. Phase 1 completed but phase 1 failed in 191.

Phase 2 error log:

Nov 7, 2014 5:52:52 PM - begin Import
Nov 7, 2014 5:53:03 PM - started process bptm (pid=307606)
Nov 7, 2014 5:53:08 PM - requesting resource A02594
Nov 7, 2014 5:53:24 PM - awaiting resource A02594. Waiting for resources. 
          Reason: Drives are in use, Media server: az33med01-bu, 
          Robot Type(Number): TLD(0), Media ID: N/A, Drive Name: N/A, 
          Volume Pool: N/A, Storage Unit: N/A, Drive Scan Host: N/A, 
          Disk Pool: N/A, Disk Volume: N/A 
Nov 7, 2014 6:16:50 PM - started process bptm (pid=307606)
Nov 7, 2014 6:16:50 PM - mounting A02594
Nov 7, 2014 6:16:50 PM - granted resource  A02594
Nov 7, 2014 6:16:50 PM - granted resource  IBM.ULT3580-TD2.004
Nov 7, 2014 6:17:22 PM - mounted A02594; mount time: 0:00:32
Nov 7, 2014 6:17:25 PM - positioning A02594 to file 37
Nov 7, 2014 6:18:31 PM - positioned A02594; position time: 0:01:06
Nov 7, 2014 6:18:37 PM - begin reading
Nov 7, 2014 6:18:39 PM - end reading; read time: 0:00:02
Nov 7, 2014 6:18:39 PM - positioning A02594 to file 38
Nov 7, 2014 6:18:39 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:18:40 PM - begin reading
Nov 7, 2014 6:20:27 PM - end reading; read time: 0:01:47
Nov 7, 2014 6:20:29 PM - positioning A02594 to file 39
Nov 7, 2014 6:20:29 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:20:29 PM - begin reading
Nov 7, 2014 6:24:11 PM - end reading; read time: 0:03:42
Nov 7, 2014 6:24:13 PM - positioning A02594 to file 40
Nov 7, 2014 6:24:13 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:24:14 PM - begin reading
Nov 7, 2014 6:26:36 PM - end reading; read time: 0:02:22
Nov 7, 2014 6:26:38 PM - positioning A02594 to file 41
Nov 7, 2014 6:26:38 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:26:39 PM - begin reading
Nov 7, 2014 6:30:58 PM - end reading; read time: 0:04:19
Nov 7, 2014 6:30:59 PM - positioning A02594 to file 42
Nov 7, 2014 6:30:59 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:30:59 PM - begin reading
Nov 7, 2014 6:32:22 PM - end reading; read time: 0:01:23
Nov 7, 2014 6:32:23 PM - positioning A02594 to file 43
Nov 7, 2014 6:32:23 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:32:24 PM - begin reading
Nov 7, 2014 6:37:30 PM - end reading; read time: 0:05:06
Nov 7, 2014 6:37:32 PM - positioning A02594 to file 44
Nov 7, 2014 6:37:32 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:37:32 PM - begin reading
Nov 7, 2014 6:41:45 PM - end reading; read time: 0:04:13
Nov 7, 2014 6:41:47 PM - positioning A02594 to file 45
Nov 7, 2014 6:41:47 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:41:47 PM - begin reading
Nov 7, 2014 6:46:15 PM - end reading; read time: 0:04:28
Nov 7, 2014 6:46:16 PM - positioning A02594 to file 46
Nov 7, 2014 6:46:16 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:46:17 PM - begin reading
Nov 7, 2014 6:48:49 PM - end reading; read time: 0:02:32
Nov 7, 2014 6:48:52 PM - positioning A02594 to file 47
Nov 7, 2014 6:48:52 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:48:53 PM - begin reading
Nov 7, 2014 6:50:30 PM - end reading; read time: 0:01:37
Nov 7, 2014 6:50:32 PM - positioning A02594 to file 48
Nov 7, 2014 6:50:32 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:50:33 PM - begin reading
Nov 7, 2014 6:54:21 PM - end reading; read time: 0:03:48
Nov 7, 2014 6:54:23 PM - positioning A02594 to file 49
Nov 7, 2014 6:54:23 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:54:24 PM - begin reading
Nov 7, 2014 6:55:52 PM - end reading; read time: 0:01:28
Nov 7, 2014 6:55:54 PM - positioning A02594 to file 50
Nov 7, 2014 6:55:54 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 6:55:55 PM - begin reading
Nov 7, 2014 7:00:28 PM - end reading; read time: 0:04:33
Nov 7, 2014 7:00:29 PM - positioning A02594 to file 51
Nov 7, 2014 7:00:29 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 7:00:29 PM - begin reading
Nov 7, 2014 7:00:31 PM - end reading; read time: 0:00:02
Nov 7, 2014 7:00:32 PM - positioning A02594 to file 52
Nov 7, 2014 7:00:32 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 7:00:33 PM - begin reading
Nov 7, 2014 7:04:56 PM - end reading; read time: 0:04:23
Nov 7, 2014 7:04:57 PM - positioning A02594 to file 53
Nov 7, 2014 7:04:57 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 7:04:57 PM - begin reading
Nov 7, 2014 7:05:14 PM - end reading; read time: 0:00:17
Nov 7, 2014 7:05:16 PM - positioning A02594 to file 54
Nov 7, 2014 7:05:16 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 7:05:17 PM - begin reading
Nov 7, 2014 7:05:55 PM - end reading; read time: 0:00:38
Nov 7, 2014 7:05:56 PM - positioning A02594 to file 55
Nov 7, 2014 7:05:56 PM - positioned A02594; position time: 0:00:00
Nov 7, 2014 7:05:58 PM - begin reading
Nov 7, 2014 7:14:10 PM - Error bpimport (pid=446930) socket read failed: errno = 73 - A connection with a remote socket was reset by that socket.
Nov 7, 2014 7:14:10 PM - Error bpimport (pid=446930) Import of policy windows-qz, schedule cum (az84hclcourdb1v-bu_1409988466) failed, file read failed.
Nov 7, 2014 7:14:10 PM - Error bpimport (pid=446930) Status = no images were successfully processed.
Nov 7, 2014 7:14:11 PM - end Import; elapsed time 1:21:19
Nov 7, 2014 7:14:11 PM - Error bpbrm (pid=283080) could not write BPBRM_READ_FILENAME message to stderr: There is no process to read data written to a pipe. (32)
Nov 7, 2014 7:14:14 PM - Error bptm (pid=307606) media manager terminated by parent process
Nov 7, 2014 7:14:15 PM - Error bptm (pid=246260) cannot write data to socket, A system call received an interrupt.
no images were successfully processed  (191)

[Dhaarani]

The tape I am using for the import id write protected. Will that be an issue ? 

[Marianne]

Write protect will not be an issue.

Did someone start the import from Remote Desktop and then closed it once the import started?

If this is not the case, you will need logs to find where the break in network connection was:

Error bpimport (pid=446930) socket read failed: errno = 73 - A connection with a remote socket was reset by that socket.

 Please also tell us where you were doing the import from -
GUI on the master? 
GUI on media server az33med01-bu ?
Remote Admin Console?

Logs needed on media server: bpbrm and bptm 
On the server where you did the import: admin and bpimport

[Dhaarani]

Marianne,

We have initiated the import from Master GUI

This was NOT done from remote console.

[sksujeet]

As Marianne pointed this is n/w break inbetween. Please try it again and make sure you provide the logs.

[Dhaarani]

08:54:43 INF - socket read failed: errno = 73 - A connection with a remote socket was reset by that socket.
 
08:54:43 INF - Import of policy windows-qz, schedule cum (az84hclcourdb1v-bu_1409988466) failed, file read failed.
 
08:54:43 INF - Status = no images were successfully processed.

[mph999]

Could you provide the logs as suggested by Marianne:

You also need to provide accurate answers to the questions

 Please also tell us where you were doing the import from -
GUI on the master? 
GUI on media server az33med01-bu ?
Remote Admin Console?

Logs needed on media server: bpbrm and bptm 
On the server where you did the import: admin and bpimport

[Dhaarani]

I tried import from my Master server GUI

[Dhaarani]

Bpbrm log:

07:32:17.589 [160002] <2> logparams: -import -secure 1 -c az33med01-bu -b az84hclcourdb1v-bu_1409988466 -cl windows-qz -ct 13 -st 4 -bt 1409988466 -mt 2 -cn 1 -L /usr/openv/netbackup/logs/user_ops/b47412/logs/jbpImport2-20141107200136.log -ru root -rclnt az33mas01 -u -v -jobid 1087688 
07:32:17.589 [160002] <2> verify_client: bpbrm.c.32937: *connect_opts: 16974338 16974338 0x01030202
07:32:17.850 [160002] <2> logconnections: BPDBM CONNECT FROM 10.64.34.230.42228 TO 10.64.34.228.13724
07:32:17.851 [160002] <2> check_authentication: no authentication required
07:32:17.851 [160002] <2> vnet_check_vxss_client_magic_wi: vnet_vxss_helper.c.770: Ignoring VxSS authentication: 2 0x00000002
07:32:17.851 [160002] <2> vnet_check_vxss_client_magic_wi: vnet_vxss_helper.c.926: Not using VxSS authentication: 2 0x00000002
07:32:18.204 [160002] <2> db_CLIENTsend: sending 45 bytes
07:32:18.254 [160002] <2> db_getCLIENT: db_CLIENTreceive: no entity was found 227
07:32:18.254 [160002] <2> bpbrm start_bpcd_stat: bpbrm.c.19608: bpcd_client: az33med01-bu
07:32:18.254 [160002] <2> bpbrm start_bpcd_stat: bpbrm.c.19611: bpcd_client_hostname: az33med01-bu
07:32:18.270 [160002] <2> hosts_equal: Comparing hosts <az33med01-bu> and <az33med01-bu>
07:32:18.270 [160002] <2> hosts_equal: names are the same
07:32:18.271 [160002] <2> local_bpcr_connect: bpcr.c.276: connect_opts = 0x01000100 connect_opts2 = 0x01000100
07:32:18.271 [160002] <2> local_bpcr_connect: bpcr.c.283: connect_opts = 0x01000100
07:32:18.271 [160002] <2> local_bpcr_connect: bpcr.c.322: daemon_port_type = 0
07:32:18.390 [160002] <2> logconnections: BPCD CONNECT FROM 10.64.60.2.42229 TO 10.64.60.2.13724
07:32:18.391 [160002] <2> bpcr_authenticate_connection: no authentication required
07:32:19.001 [160002] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 4
07:32:19.001 [160002] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 6
07:32:19.002 [160002] <2> verify_client: bpbrm.c.33129: *client_hostname: az33med01-bu
07:32:19.002 [160002] <2> verify_client: bpbrm.c.33131: *connect_opts: 16843008 16843008 0x01010100
07:32:19.024 [160002] <2> hosts_equal: Comparing hosts <az33med01-bu> and <az33med01-bu>
07:32:19.024 [160002] <2> hosts_equal: names are the same
07:32:19.024 [160002] <2> bpbrm start_bpcd_stat: bpbrm.c.19608: bpcd_client: az33med01-bu
07:32:19.024 [160002] <2> bpbrm start_bpcd_stat: bpbrm.c.19611: bpcd_client_hostname: az33med01-bu
07:32:19.024 [160002] <2> hosts_equal: Comparing hosts <az33med01-bu> and <az33med01-bu>
07:32:19.024 [160002] <2> hosts_equal: names are the same
07:32:19.024 [160002] <2> local_bpcr_connect: bpcr.c.276: connect_opts = 0x01010100 connect_opts2 = 0x01000100
07:32:19.024 [160002] <2> local_bpcr_connect: bpcr.c.283: connect_opts = 0x01010100
07:32:19.024 [160002] <2> local_bpcr_connect: bpcr.c.322: daemon_port_type = 1
07:32:19.206 [160002] <2> logconnections: BPCD CONNECT FROM 10.64.60.2.42236 TO 10.64.60.2.13724
07:32:19.206 [160002] <2> bpcr_authenticate_connection: no authentication required
07:32:19.814 [160002] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 4
07:32:19.814 [160002] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 6
07:32:19.814 [160002] <2> bpbrm main: received bpcd success message
07:32:20.015 [160002] <2> bpbrm main: from client az33med01-bu: read client start message
07:32:20.015 [160002] <2> bpbrm spawn_child: /usr/openv/netbackup/bin/bptm bptm -import -c az84hclcourdb1v-bu -bt 1415370737 -b az84hclcourdb1v-bu_1409988466 -hostname az33med01-bu -L /usr/openv/netbackup/logs/user_ops/b47412/logs/jbpImport2-20141107200136.log -ru root -rclnt az33mas01 -rclnthostname az33mas01 -v -everything -no_callback -connect_options 0x01010100 -jobid 1087688

[mph999]

OK, thats useful info but logs are still needed.

[Dhaarani]

I have provided the logs. The comment is queued for moderation by site administrators and waiting to get published after approval.

[Dhaarani]

Martin,

Please verify the bpbrm logs above.

Regards,

Dhaarani

[Marianne]

We need full logs. And all of the logs that were requested.
The section in bpbrm log only shows start of import. We need to see what happened after this...

Logs needed on media server: bpbrm and bptm 
On the server where you did the import: admin and bpimport

Please copy log files to .txt files (e.g. bpbrm.txt) and upload as File Attachments.

[Dhaarani]

Please find the complete bpbrm log

[Dhaarani]

I didnot attempt the import using bpimport command. I initiated both Phase 1 and Phase 2 from my GUI Master server.

[mph999]

... and bptm log ?

[mph999]

.

[revarooo]

No disrespect, but go back and read what logs were asked for. Partial logs are useless when troubleshooting.

[Dhaarani]

Please find the bptm log

[Dhaarani]

Please tell me from which path I need to take the logs.

I have provided here the bpbrm and bptm logs from my Master server.