Networker

Re: [Networker] nsrlcpd is not running for this jukebox

2011-01-11 16:09:40
Subject: Re: [Networker] nsrlcpd is not running for this jukebox
From: George Sinclair <George.Sinclair AT NOAA DOT GOV>
To: NETWORKER AT LISTSERV.TEMPLE DOT EDU
Date: Tue, 11 Jan 2011 16:09:09 -0500
backuphell wrote:
Thanks for responding.

The jukebox and other tape drive are showing up in device manager.  Unless I 
read wrong, both are working properly and the driver is loaded.  I had to stop 
the removeable storage service in order to run inquire.  Kicked back an error.  
This is the output from the command:

[email protected]:TEAC    DVD-ROM DW-224ECK.8A|CD-ROM
[email protected]:COMPAQ  SCSI COMMUNICATECISS|Unknown Device Type
[email protected]:HP      LOGICAL VOLUME  2.58|Disk, \\.\PHYSICALDRIVE0
                                           WWNN=600508B10010545851534C304F49FFFF
[email protected]:HP      LOGICAL VOLUME  2.58|Disk, \\.\PHYSICALDRIVE1
                                           WWNN=600508B10010545851534C304F490000
[email protected]:COMPAQ  SCSI COMMUNICATECISS|Unknown Device Type
[email protected]:HP      Ultrium 3-SCSI  G54W|Tape
[email protected]:HP      1x8 autoloader  1.50|Autochanger (Jukebox)

We're running Linux with one tape library attached to a storage node. I've had a few problems in the past with 'nsrjb' complaining that the tape library is not ready. So, for example, running something like 'nsrjb -s server' from the storage node would produce an inventory as expected, but it would also report that the library was not ready in the header output. Vary annoying! Stopping and restarting the NW software on both the primary and storage node servers did not fix it, nor did rebooting, and there appeared to be nothing wrong with the tape library itself, and the library indicated nothing amiss.

Now, I don't recall the specifics of the problem when it's occurred in the past, and what we did to correct it, but one thing that I do remember is that instead of seeing just one instance of 'nsrlcpd', I might see two at some point. We only have one tape library, and I know that I should not see two, so something was clearly wrong.

The last time this happened, we had just recently power cycled the tape library. The ugly problem reared its head once more. The 'inquire' command reported everything, but once again, same 'jukebox not ready' problem, and I'm pretty sure the weirdness with 'nsrlcpd'. After a little investigation, I realized that the control port that NMC reported was *NOT* the same as what 'inquire' was reporting. Clearly, the control port value had changed following the power cycle. Not sure if that's surprising or not. I ended up manually changing the Control port value under the library configuration in NMC to match what 'inquire' reported. Prior to that, the 'Ready' box was not checked, and then I think that fixed it, and it worked, but I think I finally ended up just reconfiguring the library using jbconfig.

Again, I'm not sure what's caused the problem in the past, but if it ever happens again, the control port value will be the first thing I'll check.

George



Below is the daemon.log file:

01/11/11 07:49:02 nsrd: server notice: started
01/11/11 07:49:15 nsrmmgd: Starting nsrmmgd.
01/11/11 07:49:18 nsrd: NetWorker
01/11/11 07:49:18 nsrd: 7.3.2.Build.364
01/11/11 07:49:18 nsrd: 364
01/11/11 07:49:18 nsrd: Wed Aug 23 19:35:24 2006
01/11/11 07:49:18 nsrd: Build arch.:  nt86
01/11/11 07:49:18 nsrd: DBG=0,OPT=
01/11/11 07:49:22 nsrindexd: Running nsrck to check client file indices
01/11/11 07:49:25 nsrmmdbd: media db is checking btrees
01/11/11 07:49:25 nsrmmdbd: media db is consistency checking the database
01/11/11 07:49:26 nsrmmdbd: media db is open for business
01/11/11 07:49:26 nsrmmgd: Started nsrlcpd on host `scd-fs1' with command line 
options '-s scd-fs1.scdirect.com -N 1 -n 1 '.
01/11/11 07:49:26 nsrd: index notice: checking index for 'ecomdb'
01/11/11 07:49:26 nsrd: index notice: C:\Program Files\Legato\nsr\index\ecomdb 
contains 714 records occupying 129 KB
01/11/11 07:49:26 nsrd: index notice: checking index for 
'crystal-util.scdirect.com'
01/11/11 07:49:26 nsrd: index notice: C:\Program 
Files\Legato\nsr\index\crystal-util.scdirect.com contains 919 records occupying 
1116 KB
01/11/11 07:49:26 nsrd: index notice: checking index for 'scd-fs1.scdirect.com'
01/11/11 07:49:26 nsrd: index notice: C:\Program 
Files\Legato\nsr\index\scd-fs1.scdirect.com contains 464763 records occupying 
68 MB
01/11/11 07:49:26 nsrd: index notice: checking index for 'scd-cfs1.scdirect.com'
01/11/11 07:49:26 nsrd: index notice: C:\Program 
Files\Legato\nsr\index\scd-cfs1.scdirect.com contains 393002 records occupying 
50 MB
01/11/11 07:49:26 nsrd: index notice: Completed checking 4 client(s)
01/11/11 07:49:26 nsrlcpd #1: Starting program `nsrlcpd #1', with process ID 
764, on HOST scd-fs1.scdirect.com.
01/11/11 07:49:27 nsrjobd: index save job on scd-fs1.scdirect.com marked 
COMPLETED during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: savegroup job on scd-fs1.scdirect.com marked 
COMPLETED during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: savegroup job on scd-fs1.scdirect.com marked 
COMPLETED during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: index save job on scd-fs1.scdirect.com marked 
COMPLETED during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: savegroup job on scd-fs1.scdirect.com marked 
COMPLETED during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-cfs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:27 nsrjobd: save job on scd-fs1.scdirect.com marked COMPLETED 
during restart of nsrjobd
01/11/11 07:49:29 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 07:49:31 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 07:49:31 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 07:49:31 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 07:49:31 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 07:49:31 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:49:31 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:49:45 nsrd: NetWork Edition
01/11/11 07:49:45 nsrd: License Summary:
01/11/11 07:49:45 nsrd:  Available: sv=10, ws=0, clu=0, clu_nt=0, clu_unix=0, 
clu_linux=0, ndmp=0
01/11/11 07:49:45 nsrd:  Borrowed:  sv_borrowed=0, clu_borrowed_nt=0, 
clu_borrowed_unix=0, clu_borrowed_linux=0
01/11/11 07:49:45 nsrd:  Remaining: sv=6, ws=0, clu=0, clu_nt=0, clu_unix=0, 
clu_linux=0, ndmp=0
01/11/11 07:49:45 nsrd:  Connected Servers: (4)
01/11/11 07:49:45 nsrd:  crystal-util.scdirect.com ecomdb scd-cfs1.scdirect.com 
scd-fs1.scdirect.com
01/11/11 07:49:48 nsrmmd #2: Start nsrmmd #2, with PID 5456, at HOST 
scd-fs1.scdirect.com
01/11/11 07:50:32 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 07:50:34 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 07:50:35 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 07:50:35 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 07:50:35 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 07:50:35 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 07:50:35 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:50:35 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:51:24 nsrd: [Jukebox `HP_autochanger', operation 1]. Initiated operation `operation: "Label"; operation device: 
"\\.\Tape0"; operation response: "prompt"; operation slots: "1-1"; operation template: 
"scd_fs1.scdirect.com.091"; operation volume pool: "Default"; '.
01/11/11 07:51:24 nsrmmgd: Jukebox `HP_autochanger' is unavailable. nsrlcpd is 
not running for this jukebox.
01/11/11 07:51:24 nsrd: [Jukebox `HP_autochanger', operation # 1]. Jukebox 
`HP_autochanger' is unavailable. nsrlcpd is not running for this jukebox.
01/11/11 07:51:24 nsrd: [Jukebox `HP_autochanger', operation # 1]. Finished 
with status: retryable
01/11/11 07:51:24 nsrmmgd: Jukebox 'HP_autochanger' is not in a valid state for 
nsrlcpd update.
01/11/11 07:52:06 nsrd: [Jukebox `HP_autochanger', operation 2]. Initiated operation `operation: "Inventory"; 
operation device: "\\.\Tape0"; operation slots: "1-1"; operation task: "verify during 
inventory"; '.
01/11/11 07:52:07 nsrmmgd: Jukebox `HP_autochanger' is unavailable. nsrlcpd is 
not running for this jukebox.
01/11/11 07:52:07 nsrd: [Jukebox `HP_autochanger', operation # 2]. Jukebox 
`HP_autochanger' is unavailable. nsrlcpd is not running for this jukebox.
01/11/11 07:52:07 nsrd: [Jukebox `HP_autochanger', operation # 2]. Finished 
with status: retryable
01/11/11 07:52:07 nsrmmgd: Jukebox 'HP_autochanger' is not in a valid state for 
nsrlcpd update.
01/11/11 07:52:36 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 07:52:38 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 07:52:39 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 07:52:39 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 07:52:39 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 07:52:39 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 07:52:39 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:52:39 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:55:40 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 07:55:42 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 07:55:44 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 07:55:44 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 07:55:44 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 07:55:44 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 07:55:44 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:55:44 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:58:45 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 07:58:47 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 07:58:49 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 07:58:49 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 07:58:49 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 07:58:49 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 07:58:49 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 07:58:49 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 08:02:50 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 08:02:52 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 08:02:54 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 08:02:54 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 08:02:54 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 08:02:54 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 08:02:54 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 08:02:54 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 08:02:55 nsrmmgd: Jukebox 'HP_autochanger' is being disabled because 
configuration of nsrlcpd 1 at host `scd-fs1' failed more than 10 times.
01/11/11 08:02:55 nsrmmgd: Disabling jukebox `HP_autochanger' due to a 
configuration problem. Correct the problem and re-enable the jukebox resource.
01/11/11 08:02:55 nsrd: Jukebox HP_autochanger is now disabled.
01/11/11 08:02:55 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 08:23:34 nsrd: media info: Suggest manually labeling a new writable 
volume for pool 'Default'
01/11/11 08:23:34 nsrd: media waiting event: Waiting for 1 writable volumes to 
backup pool 'Default' tape(s) on scd-fs1.scdirect.com
01/11/11 08:23:39 nsrmmd #3: Start nsrmmd #3, with PID 4616, at HOST 
scd-fs1.scdirect.com
01/11/11 08:38:53 nsrd: Jukebox HP_autochanger is now enabled.
01/11/11 08:38:55 nsrmmgd: Started nsrlcpd on host `scd-fs1' with command line 
options '-s scd-fs1.scdirect.com -N 1 -n 1 '.
01/11/11 08:38:56 nsrlcpd #1: Starting program `nsrlcpd #1', with process ID 
3924, on HOST scd-fs1.scdirect.com.
01/11/11 08:38:59 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 08:39:01 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 08:39:02 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 08:39:02 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 08:39:02 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 08:39:02 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 08:39:02 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 08:39:57 nsrd: media critical event: Waiting for 1 writable volumes to 
backup pool 'Default' tape(s) on scd-fs1.scdirect.com
01/11/11 08:40:03 nsrlcpd #1: Jukebox `HP_autochanger' is exiting. The jukebox 
is no longer managed by nsrlcpd.
01/11/11 08:40:05 nsrlcpd #1: Creating Jukebox `HP_autochanger'
01/11/11 08:40:07 nsrlcpd #1: Configuring Jukebox `HP_autochanger'
01/11/11 08:40:07 nsrmmgd: lcpd 1 at host scd-fs1.scdirect.com reported error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
' for the command `3'.
01/11/11 08:40:07 nsrmmgd: Configuration of jukebox `HP_autochanger' failed 
with the following error: 'Jukebox `HP_autochanger', command operation 
`CONFIG', command ID 2 is not connected.
'.
01/11/11 08:40:07 nsrmmgd: Jukebox 'HP_autochanger' is unavailable. The config 
command failed on nsrlcpd 1 for host `scd-fs1'. Retrying..
01/11/11 08:40:07 nsrmmgd: mgd_process_admin_response: failed to process 
response for command 3 from lcpd 1 at host scd-fs1.scdirect.com with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.
01/11/11 08:40:07 nsrmmgd: nsrlcpd response processing failed with error 
'Jukebox `HP_autochanger', command operation `CONFIG', command ID 2 is not 
connected.
'.

The jukebox keeps asking for writable media, but the tapes are set to overwrite if need be. That is recorded a lot in the event logs.
Any clues based on the log files?

+----------------------------------------------------------------------
|This was sent by cmaligno AT scdirect DOT com via Backup Central.
|Forward SPAM to abuse AT backupcentral DOT com.
+----------------------------------------------------------------------

To sign off this list, send email to listserv AT listserv.temple DOT edu and type 
"signoff networker" in the body of the email. Please write to networker-request 
AT listserv.temple DOT edu if you have any problems with this list. You can access the 
archives at http://listserv.temple.edu/archives/networker.html or
via RSS at http://listserv.temple.edu/cgi-bin/wa?RSS&L=NETWORKER



--
George Sinclair
Voice: (301) 713-3284 x210
- The preceding message is personal and does not reflect any official or unofficial position of the United States Department of Commerce -
- Any opinions expressed in this message are NOT those of the US Govt. -

To sign off this list, send email to listserv AT listserv.temple DOT edu and type 
"signoff networker" in the body of the email. Please write to networker-request 
AT listserv.temple DOT edu if you have any problems with this list. You can access the 
archives at http://listserv.temple.edu/archives/networker.html or
via RSS at http://listserv.temple.edu/cgi-bin/wa?RSS&L=NETWORKER