Backup Failed. Log not too helpful...

mattfuerst · ‎04-10-2012

We made some drastic changes to our UC 560 and I'm trying to do a backup via CCA 3.1

I've done this successfully before, but now I'm getting the following error:

"Backup failed. See log for more details."

Pro tip for anyone, the log will not be in CCA, as far as I can tell. The file they mean is going to be roughly in:

C:\Program Files (x86)\Cisco Systems\CiscoSMB\Cisco Configuration Assistant

Here's what looks like the important bits from that file...

se-10-1-10-1#

10:38:01,259 [DEBUG] Issuing backup command.

10:38:06,259 [DEBUG]

*************attempting to session to cue************

10:38:06,260 [DEBUG] AuthGrp@adf91: getAuthCreds() called for: telnet://192.168.10.1:23; realm: null

10:38:08,451 [DEBUG] AuthGrp@adf91: getAuthCreds() called for: telnet://192.168.10.1:23; realm: null

10:38:09,789 [DEBUG] Current CUE transport timeout =90000

10:38:09,789 [DEBUG] Current CUE deliver timeout =600

10:38:11,099 [DEBUG] Session clear command sent

10:38:11,765 [DEBUG] Session command = service-module Integrated-Service-Engine 0/0 session

10:38:15,322 [DEBUG] Logged into CUE.

10:38:17,086 [DEBUG] Learned CUE Prompt = se-10-1-10-1#

10:38:18,350 [DEBUG] SetPrivExecMode() done - CUE Prompt = se-10-1-10-1#

10:38:20,060 [DEBUG] Set CUE transport timeout =90000

10:38:20,060 [DEBUG] Set CUE deliver timeout =90000

10:38:20,060 [DEBUG]

*************CUE prompt: se-10-1-10-1# *************

10:38:20,060 [DEBUG]

*************attempting to session successful************

10:38:20,060 [DEBUG]

*************CUE prompt: se-10-1-10-1# *************

10:38:40,730 [DEBUG]

received offline#

10:39:01,920 [DEBUG] Obtaining the output of CLI: backup category all

10:39:02,590 [ERROR] [INFO] RequestHandler - Open connection - 10.1.10.1

10:39:02,593 [ERROR] [INFO] PASS - Login success - cisco

10:39:02,593 [ERROR] [INFO] RequestHandler - Close connection : 10.1.10.1 - cisco

10:39:02,598 [ERROR] [INFO] RequestHandler - Open connection - 10.1.10.1

10:39:02,600 [ERROR] [INFO] PASS - Login success - cisco

10:39:32,606 [ERROR] [INFO] RequestHandler - Close connection : 10.1.10.1 - cisco

10:39:32,666 [ERROR] [INFO] RequestHandler - Open connection - 10.1.10.1

10:39:32,667 [ERROR] [INFO] PASS - Login success - cisco

10:39:32,670 [ERROR] [INFO] MKD - Directory create : cisco - /cue/TimeCardView_1

10:39:46,721 [ERROR] [INFO] ConnectionManagerImpl - Removing idle data connection for cisco

10:39:52,666 [ERROR] [INFO] RequestHandler - Close connection : 10.1.10.1 - cisco

10:40:46,085 [DEBUG]

received CUE#

10:41:37,097 [INFO ] [cmd: backup category all, status: 0, output: [4lBackup progress: 0 bytes

Backup Failed.

Check Backup history for detailed information.

[4hse-10-1-10-1(offline)#]

10:41:37,097 [ERROR] doCueBackup(): Did not find 'Backup Complete' in response.

10:41:37,097 [ERROR] com.cisco.cpnm.features.defn.backrest.BackrestException: Backup CUE Configuration failed.

10:41:37,097 [ERROR] at com.cisco.cpnm.features.defn.backrest.CommonArchiveConfiguration.conductBackup(CommonArchiveConfiguration.java:361)

10:41:37,097 [ERROR] at com.cisco.cpnm.features.defn.backrest.CommonArchiveConfiguration.conductBackup(CommonArchiveConfiguration.java:262)

10:41:37,097 [ERROR] at com.cisco.cpnm.features.defn.backrest.BackupRestoreConfigTask$BackupWorkerThread.run(BackupRestoreConfigTask.java:1267)

10:41:37,097 [ERROR] at com.cisco.cpnm.frmwrk.gen.util.ThreadPool$WorkerThread.run(ThreadPool.java:1010)

10:41:37,098 [DEBUG] Backup Failed for UC_560: Backup CUE Configuration failed.

10:41:37,121 [DEBUG] Duration for [upd Mirror<--Device() @ com.cisco.cpnm.features.defn.backrest.BackupRestoreConfigTask] = [410604] msec.

10:45:36,305 [ERROR] A widget could not be serialized because its id was not set.

10:45:36,307 [DEBUG] WDTask::setHierarchy .BackupRestoreConfigTask

10:45:38,446 [ERROR] [INFO] FtpServer - ------- Apache FTP Server started ------

10:45:39,446 [INFO ] isTFTPorFTPAvail():FTP and TFTP Services are available.

10:45:39,447 [DEBUG] WDTask::setHierarchy .BackupRestoreConfigTask

10:45:39,456 [DEBUG] WDTask::setHierarchy .BackupRestoreConfigTask.BackupRestoreConfigTask$BackupConfigTask

10:45:39,457 [ERROR] A widget could not be serialized because its id was not set.

10:45:39,457 [DEBUG] WDTask::setHierarchy .BackupRestoreConfigTask.BackupRestoreConfigTask$RestoreConfigTask

10:45:39,457 [DEBUG] Duration for [create() @ com.cisco.cpnm.features.defn.backrest.BackupRestoreConfigTask] = [6] msec.

10:45:39,505 [DEBUG] Duration for [upd Mirror<--Device() @ com.cisco.cpnm.features.defn.backrest.BackupRestoreConfigTask$BackupConfigTask] = [35] msec.

10:45:39,505 [DEBUG] Duration for [upd Mirror<--Device() @ com.cisco.cpnm.frmwrk.gen.wd.WDTabbedPane] = [36] msec.

10:45:39,525 [DEBUG] Duration for [upd Mirror<--Device() @ com.cisco.cpnm.features.defn.backrest.BackupRestoreConfigTask$RestoreConfigTask] = [17] msec.

Nothing particularly interesting I can see there. One interesting bit is: "Check Backup history for detailed information." The irony of going 3 levels deep trying to find the root cause is not lost on me. Any hints what exactly it's recommending there? Where is the backup history stored? I can't see anything interesting in the Configuration Archive in CCA (which seemed like a logical place for Backup History).

danplacek · ‎04-10-2012

That message was generated by CUE not CCA. The backup history you need to check is CUE's.

Try: http://10.1.10.1/ -- Log in, then goto Reports -> Backup History.

mattfuerst · ‎04-10-2012

Thanks a ton Daniel...

Popping into the web interface, I see..

TimeCardView: Failure Connection to backup server failed: ftp://192.168.10.36/cue/: returnvalue:28 Connection timeout

TimeCardView: Failure Connection to backup server failed: ftp://192.168.10.36/cue/: returnvalue:7 Unable to connect to backup server

TimeCardView: Failure Connection to backup server failed: ftp://192.168.10.36/cue/: returnvalue:28 Connection timeout

.36 is my desktop PC. From looking at it, I guess CCA opens up a temporary (?) ftp server on my desktop PC, for the 560 to transfer the backup file to me, is that correct? And this process is failing for some reason?

My firewall status has not changed in the past month since I backed up last...

I'm not running an FTP server or anything on my PC (so, the port is not in use now)

Does CCA run an FTP Server on the traditional FTP ports? I could monitor the ports and see if anything opens up or gets denied.

Has anyone else experienced this? I may also be reading this completely wrong, but I would guess that is how the backup works.

danplacek · ‎04-10-2012

Yes, CCA runs both a FTP and TFTP server on your PC to transfer files back and forth.

If you are familar with Wireshark or some other packet sniffer, I would recommend giving that a go -- if you need help analyzing the results, I would be happy to help.

Of course all the standard networking advice applies as well -- try turning off your firewall, etc.

Somewhere around here there is a document detailing all the requirements for CCA to run properly... I don't have the link offhand, but you can probably find it in the documents section. (the list of requirements is longer than you might think)

Daniel Moroz · ‎06-30-2017

Hi Matt, this is going back 5 years or so, but I'm having the same backup issues as you had on my UC.

Did you ever resolve the problem and if so, can you remember what it is that you did to fix it? Pinging is not an issue from the UC to my PC and vice-versa.

Let me know if you get the chance!

Thanks Dan

mattfuerst · ‎04-10-2012

Very interesting, thanks Dan.

I tried using Active Ports (a handy older utility that monitors all open ports and the associated executable) but it apparently isn't Win 7 friendly. We tried the backup process on 3 different computers (including an old XP box with no firewall at all) and all failed with the same error codes.

I thought the Microsoft Process Monitor would help me out, and it will list network activity but it doesn't give port numbers as far as I can tell, which makes it tougher to diagnose.

Seems like something else is afoot, but I don't have time at the moment to go any deeper. Hope to revisit this later in the week.

Alexander Maroukian · ‎04-10-2012

Hi,

Could you please try the following:

Check the connectivity from the UC500 to your PC please choose Troubleshoot > Network Diagnostics >

Ping from the feature bar. There select the interface with IP address 10.1.10.2 and ping the ip address of your PC in the destination ip address field and press start.

You should be able to ping from both directions. If not please check you Access lists - Configure -> Security > ACL Manager and see if you are blocking traffing between these networks.

If connectivity is ok try to restart CCA.

HTH,

Alex

*Please rate helpful posts

Brian Rapier · ‎06-21-2012

I ran into the exact problem. Here is what I had to do to resolve it, so far its working as it should.

I could ping from the PC running CCA to the 10.1.10.2 but I could not ping from the 10.1.10.2 to the PC. I am behind an ASA and I noticed that the pings were being blocked with "No matching session"

So I added a static route on the PC running CCA to point to the UC560 data connection (in my case 192.168.0.15). Why the static route on the ASA is not working I have not sorted out yet.

For Window 7 here is the command typed at an administrative command line.

route add 10.1.10.0 MASK 255.255.255.252 192.168.0.15 (your UC data IP)

Now if I can just get the rest of the UC working I would be all set, but at least I can back it up and run upgrades. Its a workaround but its doing the job.

Hope this helps.