Getting error message “98 "error requesting media (tpreq)" intermittently

[Yaqoob_Qaudri]

I am getting error message intermitantly, For backup1 just ignore the ndmp error that is known to us.

Backup1  : Policy : NJ09MHFNAS320_11year

Resource Granted  :
03/28/2015 11:52:58 - granted resource  PF1587
03/28/2015 11:52:58 - granted resource  SL8500B_Drive_08
03/28/2015 11:52:58 - granted resource  hts-esb-10-hcart-robot-acs-13-nj09mhfnas320

03/28/2015 11:53:05 - Info bptm (pid=7671) Waiting for mount of media id PF1587 (copy 1) on server hts-esb-10.
03/28/2015 11:53:05 - mounting PF1587
03/28/2015 11:53:06 - Error bptm (pid=7671) cannot open ndmp device c192t0l0, error code 7 (NDMP_IO_ERR)
03/28/2015 12:25:48 - Error bptm (pid=7671) error requesting media, TpErrno = Robot operation failed
03/28/2015 12:25:48 - Error bptm (pid=7671) cannot open ndmp device c192t0l0, error code 7 (NDMP_IO_ERR)
03/28/2015 12:25:48 - Warning bptm (pid=7671) media id PF1587 load operation reported an error
03/28/2015 12:25:48 - current media PF1587 complete, requesting next media Any
03/28/2015 13:00:33 - Error ndmpagent (pid=7660) NDMP backup failed, path = UNKNOWN
03/28/2015 13:00:33 - end writing
03/28/2015 13:00:38 - Info bptm (pid=7671) EXITING with status 98 <----------
03/28/2015 13:00:38 - Info ndmpagent (pid=0) done. status: 98: error requesting media (tpreq)
error requesting media (tpreq)  (98)

Backup2 : Policy : user_UNIX

Resource Granted Details

03/28/2015 11:52:58 - granted resource  PF1587

03/28/2015 11:52:58 - granted resource  SL8500B_Drive_08

03/28/2015 11:52:58 - granted resource  hts-esb-10-hcart-robot-acs-13-nj09mhfnas320

03/28/2015 22:38:05 - Info bpbrm (pid=1902) terminating bpbrm child 11497 jobid=20209057

03/28/2015 22:38:05 - end writing

error requesting media (tpreq)  (98)

Backup3 : Policy : SQLBackups01_02_04_05_06

10.NBU_POLICY.MAXJOBS.SQLBackups01_02_04_05_06

03/28/2015 01:24:52 - granted resource  IV8459

03/28/2015 01:24:52 - granted resource  SL8500A_Drive_46

03/28/2015 01:24:52 - granted resource  nj09esb210-hcart4-acs12

03/28/2015 02:02:31 - Info bpbrm (pid=18480) terminating bpbrm child 19002 jobid=20206388

03/28/2015 02:02:31 - end writing

error requesting media (tpreq)  (98)

I have tried below steps to fix the issue but no luck

• There is enough space in / disk 
• media IDs are not being used for illegal characters.
• Communication with library and vice versa ,using robtest is fine
• Library side query issues on ACS server looking good
• all  lsm,lmu,cap,port showing onlne status.

I have attached snipped media manager logs for backup1 . Any help would be highly appreciated.

[Nicolai]

Still looking, but this need to be fixed first :

ACS(13) dismount failure for volume PF2653 on drive (0,3,1,2), ACS status = 29, STATUS_DRIVE_IN_USE

From acsls diskmount the tape drives 

# dismount PF2653 0,3,1,2 force

The tape drive may need reboot from SL console first

[Nicolai]

What does /export/home/ACSSS/log/event.log say ?

Any error messages ?

[RiaanBadenhorst]

For this policy there is some issue with the media (or drive)

03/28/2015 11:53:06 - Error bptm (pid=7671) cannot open ndmp device c192t0l0, error code 7 (NDMP_IO_ERR)
03/28/2015 12:25:48 - Error bptm (pid=7671) error requesting media, TpErrno = Robot operation failed
03/28/2015 12:25:48 - Error bptm (pid=7671) cannot open ndmp device c192t0l0, error code 7 (NDMP_IO_ERR)
03/28/2015 12:25:48 - Warning bptm (pid=7671) media id PF1587 load operation reported an error

Might want to probe the filer and see if the devices are still available.

[Marianne]

Seems tape cannot be mounted because a reservation is still held by another media server.

Check drive status in ACSLS to see if tape is still mounted on the drive.

If you enable acsss_stats log (Library Volume Statistics) on ACSLS server, you will be able to see which media server/ip address has last mounted the tape and if dismount request was received from the same media server.

If SSO environment, have a look at 'vmdareq' output and also 'vmoprcmd' on the master to see which media server has the drive currently assigned.

Incorrect device mapping is normally the culprit here - if no Persistent Binding is done between hba and OS on all media servers, device paths may change when a server is rebooted, resulting in incorrect device mappings. 

[Yaqoob_Qaudri]

I am getting below messages in acs event logs.

03-28-2015 00:35:13 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 51554 failed on "Connection refused"
03-28-2015 00:35:13 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 01:41:16 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 63975 failed on "Connection refused"
03-28-2015 01:41:16 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 04:31:40 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 52511 failed on "Connection refused"
03-28-2015 04:31:40 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 06:14:27 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 64716 failed on "Connection refused"
03-28-2015 06:14:27 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 07:24:24 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 40719 failed on "Connection refused"
03-28-2015 07:24:24 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 09:38:16 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 60517 failed on "Connection refused"
03-28-2015 09:38:16 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 11:17:00 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 39293 failed on "Connection refused"
03-28-2015 11:17:00 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 15:47:19 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 36697 failed on "Connection refused"
03-28-2015 15:47:19 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

03-28-2015 16:20:32 SSI[0]:
[cl_ipc_write.c:141] cl_ipc_write: Sending message to socket 40456 failed on "Connection refused"
03-28-2015 16:20:32 SSI[0]:
[csi_rpcdisp.c:515] ONC RPC: csi_rpcdisp(): status:STATUS_IPC_FAILURE;  
Cannot send message To Client:discarded;

[Nicolai]

This does not look right - do you have firewalls installed ?

[Yaqoob_Qaudri]

No firewall installed 

[Marianne]

Enable acsss_stats log (Library Volume Statistics) on ACSLS server to see where mount/dismount requests are coming from. 

If you have media servers with multiple NICs, add
ACS_SSI_HOSTNAME = <hostname>
 to vm.conf to ensure ACS comms always happen on correct interface.

PS:
Lots of good info in this TN:
http://www.symantec.com/docs/TECH31526 

[Yaqoob_Qaudri]

However I have opened a case with Oracle to check the ACS Library end. I will keep posted.

[Yaqoob_Qaudri · Accepted solution]

I have found that Avamar was doing backups of this NDMP filer at the same time which causes the problem ,So I have migrated these clients on Avamer and now backups completing successfully using Avamar.