Ciscoworks failing to sync archive/netconfig using TFTP

[nrmdcs]

I had been getting an error when I attempt to deploy a netconfig job with the sync archive before execution checkbox checked.  When I try a job without this checkbox checked Ciscoworks will instead not attempt to deploy to these devices.

The error I see when trying to deploy a netconfig is: "ERROR:RME_CDL1032:Synchronization of the running configuration before deploy, has failed"

When I try to manually sync archive the execution result is: "Unable to get results of job execution for device. Retry the job after  increasing the job result wait time using the option:Resource Manager Essentials  -> Admin -> Config Mgmt -> Archive Mgmt ->Fetch Settings" - I have tried increasing the time out to no effect.

If I remove TFTP as a transport option for Archive Mgmt and Netconfig in RME > Admin > Transport Settings I can sync archive and deploy netconfig jobs so I am assuming there is something wrong with TFTP.  I tested that TFTP works by creating CSCOpx\tftpboot\test.txt and then copying the config from a device to that file over TFTP.  I've checked all the permissions to ensure that causers has full control over what it needs and it does so I'm a bit stumped.

I'm running:

LMS 3.2

Common Services 3.3.0

RME 4.3.0

From what I have been able to gather it stopped working on the 30th of June, and on that day the following software installation was completed to add the latest Cat3560 package to support Cat3560v2 devices:  Cat3560(7.1) ,LibCommon(2.4.1) ,LibInventory(3.1.3) ,LibSwim(2.5.2) ,SharedSwim2900XL(2.2.1) ,SharedSwimIOS(2.5.1)

I'm assuming one of the Lib dependencies that was installed may have broken TFTP somehow but as I cannot find anything in logs to indicate this I'm not sure that I am on the right track.

Anyone have any bright ideas?

Thanks!

[Joe Clarke]

If one of the transports fail, RME should move to the next one in order.  The error you're seeing is typically seen when SSH is enabled because of a bug in RME.  If you now add TFTP back (and do nothing else), does the problem reoccur?

[nrmdcs]

I added it back as the first transport method (followed by SSH/telnet) and it fails straight away.

[Joe Clarke]

Start a sniffer trace filtering on all traffic to one test device.  Then perform a config sync or Netconfig job for that device (to reproduce the failure).  Post the capture file.

[nrmdcs]

During the packet capture I noticed that there would be a number of SNMP requests and then the job status in the netconfig job browser would change to failed, and THEN I'd see some more SNMP requests followed by SSH activity and a TFTP transfer take place.

Attached is the capture file.

[Joe Clarke]

TFTP requires you to have read-write SNMP credentials configured in DCR.  It does not appear that this is the case.  The TFTP transfer you see

after the SSH packets is a transfer of the vlan.dat file.  The way RME transfers vlan.dat is to login via telnet or SSH, then executes "copy flash:vlan.dat tftp:".  Based on what I'm seeing here, it looks like the archive job completes successfully.  I cannot be 100% certain, though because I can't decrypt the SSH traffic.  But based on the sheer number of packets, it looks good.

[nrmdcs]

That output was from a netconfig job with the sync archive before job execution checkbox checked.  read-write credentials are definitely set in DCR, and all of this worked prior to the 3560 package upgrade .  I take it those first series of snmp requests should be using the rw snmp string rather than the ro string?

[Joe Clarke]

No.  There should only be one SET request to trigger a TFTP copy.  Can you try a Sync Archive job instead, and see if it still fails?

[nrmdcs]

The job has been running on a single device for the last ten minutes, and I'm not seeing any traffic over the monitor session.  Is there a log file that records TFTP attempts?

[Joe Clarke]

The dcmaservice.log tracks the activities.  However, I'm wondering if ConfigMgmtServer is already locked up.  Try restarting this daemon, then try to run the sync archive job again:

pdterm ConfigMgmtServer

pdexec ConfigMgmtServer

[nrmdcs]

Tried restarting ConfigMgmtServer, no lucky unfortunately. 

[Joe Clarke]

Are you seeing any new traffic in the sniffer trace?  Post the dcmaservice.log after running the sync archive job.

[nrmdcs]

Edit:  Replied to original post instead.

[nrmdcs]

dcmaservice.log:

[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.ConfigManager,updateArchive,1941,Sync Archive for 1 devices - Sync Archive
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.ConfigManager,updateArchive,1955,Number of devices in fetch Q = 0
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.ConfigManager,addToDeviceIdToReqIdMap,2289,Device Id 3961 already in Q
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.CfgThreadManager,compareDeviceWithDevicesinRunningThreads,59,inside compareDeviceWithDevicesinRunningThreads method
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.CfgThreadManager,compareDeviceWithDevicesinRunningThreads,60,Total running threads:5
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.ConfigManager,updateArchiveIfRequired,2029,Compared the device with running thread devices.Adding to start of Fetch Q
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-5],com.cisco.nm.rmeng.dcma.configmanager.CfgThreadManager,triggerConfigFetch,52,#### Start of Sweep Thu Jul 15 08:39:04 EST 2010 ####
[ Thu Jul 15  08:39:04 EST 2010 ],INFO ,[Thread-1],com.cisco.nm.rmeng.dcma.configmanager.CfgThreadManager,run,99,#### End of Sweep Thu Jul 15 08:39:04 EST 2010 ####

Not sniffing any new traffic, still just the read only snmp hits.

While running the jobs I noticed the following in ConfigMgmtServer.log.  I re-ran the job to just to make sure that the sync archive job was triggering it and it does seem to line up (alas there are no time stamps in ConfigMgmtServer.log):

Exception in thread "Thread-27" java.lang.NoSuchMethodError: com.cisco.nm.xms.xdi.pkgs.LibCommon.common.ServerAddress.getAddress(Ljava/lang/String;Ljava/util/Properties;)Ljava/lang/String;
at com.cisco.nm.xms.xdi.pkgs.LibDcma.util.Util.getServerIPAddress(Util.java:263)
at com.cisco.nm.xms.xdi.pkgs.SharedDcmaIOS.transport.IOSTftpOperator.fetchConfig(IOSTftpOperator.java:132)
at com.cisco.nm.xms.xdi.pkgs.SharedDcmaIOS.transport.IOSTftpOperator.fetchConfig(IOSTftpOperator.java:94)
at com.cisco.nm.xms.xdi.pkgs.LibDcma.persistor.SimpleFetchOperation.performOperation(SimpleFetchOperation.java:61)
at com.cisco.nm.xms.xdi.pkgs.LibDcma.persistor.ConfigOperation.doConfigOperation(ConfigOperation.java:111)
at com.cisco.nm.xms.xdi.pkgs.SharedDcmaIOS.transport.IOSConfigOperator.fetchConfig(IOSConfigOperator.java:71)
at com.cisco.nm.rmeng.dcma.configmanager.ConfigManager.updateArchiveForDevice(ConfigManager.java:1315)
at com.cisco.nm.rmeng.dcma.configmanager.ConfigManager.performCollection(ConfigManager.java:3291)
at com.cisco.nm.rmeng.dcma.configmanager.CfgUpdateThread.run(CfgUpdateThread.java:27)

I've checked that I can tftp configuration off of the devices i'm testing with to the Ciscoworks boxes.

[Joe Clarke · Accepted solution]

This points to a problem with your LibCommon package in RME.  If you shutdown ConfigMgmtServer, then restart, and try

the job again, does this NoSuchMethodError return?  If so, you should contact TAC to get an up-to-date consistent RME package repository which should fix this.  You should also confirm that you do not have a ServerAddress.class file on the system under a com/cisco/nm/xms/xdi/pkgs/LibCommon/common directory tree.