unable to automatically mount new tape

[tekkanet]

Hello,
I have Networker 7.3.2 installed and scsi connected to a PV132T library.
It is some time that when a tape becomes full, Networker is unable to switch it automatically.
Then if I manually mount a new volume (the one that gets problems in automatic during backup operations for example), all is ok.
I suspect that the problem arised after passing from 7.2 to 7.3 and it sill remains in 7.3.2.
The error I get in daemon.log is this:

11/09/06 00:40:47 nsrd: mailserver:MSEXCH:MB/username saving to pool 'Default' (000004)
11/09/06 00:41:33 nsrd: media warning: /dev/nst0 writing: No space left on device, at file 530 record 804
4
11/09/06 00:41:33 nsrd: media notice: LTO Ultrium-2 tape 000004 on /dev/nst0 is full
11/09/06 00:41:33 nsrd: media notice: LTO Ultrium-2 tape 000004 used 337 GB of 190 GB capacity
11/09/06 00:42:22 nsrd: media info: verification of volume "000004", volid 2756059030 succeeded.
11/09/06 00:42:31 nsrd: write completion notice: Writing to volume 000004 complete
11/09/06 00:42:31 nsrd: Operation 24 started : Load volume `000012'.
.
11/09/06 00:42:31 nsrd: media waiting event: Waiting for 1 writable volumes to backup pool 'Default' tape
(s) on bcksrv.peviani.it
11/09/06 00:42:33 nsrmmd #2: Start nsrmmd #2, with PID 29599, at HOST bcksrv.peviani.it
11/09/06 00:42:35 nsrd: [Jukebox `PV132T', operation # 24]. Cannot find an available nsrmmd service for operation on device '/dev/nst0'. Try again.
11/09/06 00:42:35 nsrmmgd: Cannot find an available nsrmmd service for operation on device '/dev/nst0'. Try again.
11/09/06 00:42:37 nsrmmgd: Jukebox `PV132T' failed to load the requested volume.
11/09/06 00:42:41 nsrd: [Jukebox `PV132T', operation # 24]. Finished with status: retryable
11/09/06 00:42:41 nsrmmgd: RAP error: Invalid resource data.
11/09/06 00:42:41 nsrmmgd: Cannot update operation status resource (instance 24).

11/09/06 00:42:55 nsrd: media info: Suggest manually labeling a new writable volume for pool 'Default'
11/09/06 00:52:35 nsrd: Operation 25 started : Unload jukebox device `/dev/nst0'.
.
11/09/06 00:52:35 nsrd: /dev/nst0 Eject operation in rogress
11/09/06 00:53:27 nsrd: [Jukebox `PV132T', operation # 25]. Finished with status: succeeded
11/09/06 00:58:14 nsrd: media critical event: Waiting for 1 writable volumes to backup pool 'Default' tape(s) on bcksrv.peviani.it

Then in the morning when I check and manually do the mount operartion all is ok:

11/09/06 07:51:08 nsrd: [Jukebox `PV132T', operation 26]. Initiated operation `operation: "Load"; operation device: "/dev/nst0"; operation slots: " 9"; write enabled: "Yes"; '.
11/09/06 07:51:26 nsrd: media request alert: Waiting for 1 writable volumes to backup pool 'Default' tape on bcksrv.peviani.it
11/09/06 07:51:30 nsrd: /dev/nst0 Verify label operation in progress
11/09/06 07:51:33 nsrd: /dev/nst0 Mount operation in progress
11/09/06 07:51:34 nsrd: media request alert: Waiting for 0 writable volumes to backup pool 'Default' tape on bcksrv.peviani.it
11/09/06 07:51:34 nsrd: media event cleared: Waiting for 1 writable volumes to backup pool 'Default' tape
(s) on bcksrv.peviani.it
11/09/06 07:51:34 nsrd: mailserver:MSEXCH:MB/user2 saving to pool 'Default' (000007) 196 MB

Any hints? Any configuration problem could cause this?
Thanks in advance for your help.

Gianluca

 

[605]

It seems that the drive daemon nsrmmd dies and some seconds later the jukebox manager daemon reports an "invalid resource data" for whatever reason. 10 minutes later the device will be unloaded due the the "idle device timeout".

Let me suggest that you check your jukebox settings. Worst case, reinstall the jukebox.

 

[tekkanet]

What would you suggest to check the jukebox setings: the mgmt console gui or from commmand line with jbconfig?

 

[605]

Both are fine ... and of course the result should be the same. But being an old-time user, i would prefer jbconfig.

 

[stug]

I have been experencing this same problem. I have been able to avoid this problem by rebooting my Networker server once a week.

 

[tekkanet]

Hello,
I deleted library and tape device from within the mgmt console gui.
Then I recreated them with the jbconfig command.
I waited till the tape in use became full to see what would have happened.
The result seems again the same error at the first try, but instead of saying
11/09/06 00:42:55 nsrd: media info: Suggest manually labeling a new writable volume for pool 'Default'
11/09/06 00:52:35 nsrd: Operation 25 started : Unload jukebox device `/dev/nst0'.
it says:
11/23/06 19:01:18 nsrd: Operation 2 started : Load volume `000013'.
.
and successfully loading the next available volume.
If you have any comments, they are welcome... see below entire messages.

11/23/06 19:01:08 nsrd: Operation 1 started : Load volume `000013'.
.
11/23/06 19:01:08 nsrd: media waiting event: Waiting for 1 writable volumes to backup pool 'Def
ault' tape(s) on bcksrv.peviani.it
11/23/06 19:01:10 nsrmmd #2: Start nsrmmd #2, with PID 10248, at HOST bcksrv.peviani.it
11/23/06 19:01:12 nsrd: [Jukebox `PV132T', operation # 1]. Cannot find an available nsrmmd service for operation on device '/dev/nst0'. Try again.
11/23/06 19:01:12 nsrmmgd: Cannot find an available nsrmmd service for operation on device '/dev/nst0'. Try again.
11/23/06 19:01:12 nsrmmgd: Jukebox `PV132T' failed to load the requested volume.
11/23/06 19:01:15 nsrd: [Jukebox `PV132T', operation # 1]. Finished with status: retryable
11/23/06 19:01:15 nsrmmgd: RAP error: Invalid resource data.
11/23/06 19:01:15 nsrmmgd: Cannot update operation status resource (instance 1).
11/23/06 19:01:18 nsrd: Operation 2 started : Load volume `000013'.
.
11/23/06 19:01:21 nsrd: /dev/nst0 Eject operation in progress
11/23/06 19:03:28 nsrd: /dev/nst0 Verify label operation in progress
11/23/06 19:03:31 nsrd: /dev/nst0 is now enabled read/write
11/23/06 19:03:31 nsrd: /dev/nst0 Mount operation in progress
11/23/06 19:03:31 nsrd: media event cleared: Waiting for 1 writable volumes to backup pool 'Default' tape(s) on bcksrv.peviani.it
11/23/06 19:03:32 nsrd: vcenter:C:\ saving to pool 'Default' (000013)
11/23/06 19:03:32 nsrd: vcenter:\ saving to pool 'Default' (000013)
11/23/06 19:03:36 nsrd: [Jukebox `PV132T', operation # 2]. Finished with status: succeeded
pools supported: Default;
11/23/06 19:04:12 nsrd: vcenter:\ done saving to pool 'Default' (000013) 6875 KB
11/23/06 19:04:31 nsrd: vcenter:C:\ done saving to pool 'Default' (000013) 104 MB
11/23/06 19:04:31 nsrd: bcksrv.peviani.it:index:vcenter saving to pool 'Default' (000013)
11/23/06 19:04:31 nsrd: bcksrv.peviani.it:index:vcenter done saving to pool 'Default' (000013)4533 KB
11/23/06 19:04:31 nsrd: savegroup notice: vcenter completed, Total 1 client(s), 1 Succeeded. Please see group completion details for more information.

 

[605]

There is a process running on the server (nsrmon) which checks the availability of devices. Each active device will cause the server to start one nsrmmd process at the local/remote storage node. If it "dies", the NW server will try to restart it. It seems that it failed here. However, i can not tell you why.