Very slow backups

Question

I have a couple of W2K clients (7.2) here which are being newly configured. We set them up on ssbak13 (7.1.2) the other day and they went pretty slow (100Kb/s over a dedicated 100Mb network to LTO drives with nothing else running at the same time). The project manager didn't give me time to investigate but instead had me move them to another Networker server ssbak12 (7.3) where we had identical problems.

Running a save -D9 from one of the clients it fails as such:

save: mmsave setup failed: Warning, cannot resolve host 'UKWAP346' to '10.102.5.
12', name server may be misconfigured.
save: direct save returns: Warning, cannot resolve host 'UKWAP346' to '10.102.5.
12', name server may be misconfigured.
save: error, Warning, cannot resolve host 'UKWAP346' to '10.102.5.12', name serv
er may be misconfigured. (number -7)
save: Cannot open save session with ssbak12
save completion time: 2-23-06 4:54p
save: win32_post_save(): Called
C:\Documents and Settings\Administrator>

We have acknowledged there is a Windows reverse DNS issue on the backup interface card ukwap346-bak but I'm curious why it would be backing up at all if this was the case!?! All aliases are configured on the Networker resource; the UNIX DNS server correctly does reverse lookups of 10.102.5.12 to ukwap346-bak and the server network interface is configured as ssbak12-bk (we have also tried this with server network interface field blank).

brooks2 · Answer

Verify the settings of the negotiation of the network adaptors and the switch ports they are connected to. Sometimes they are not in sync or should both be forced to full/100.-Brooks

ble1 · Answer

What Brooks said is suspect number one. Suspect number two (when it comes to system related stuff) are TCP settings on both end. Usually you are able to confirm something is wrong by doing ftp test with put and get (bare in mind that transaction in one direction may result in expected speed). But I would also start by checking what Brooks said and verifying that with some systems tools as well.

ble1 · Answer

NIC setting can be correct, but if the port setting on switch is not set correctly you may see the same problem again so check that too.

DavidHampson · Answer

We have already verified the settings of the network cards hard set to 100M full duplex. We may move on to doing some ftp tests but first thing we are going to do is configure HOSTS file and see what impact that has.

DavidHampson · Answer

7.3 did not solve the problem...!The backup appears to hang - here are the final few lines from the save -D9:save: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781869save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 10124save: socket bound to port 20513save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 21508save: socket bound to port 20042save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_auth: redirected to ssbak12 prog 390103 vers 2save: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781869save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 23962save: socket bound to port 13936save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 25351save: socket bound to port 21708save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_auth for `nsrd' succeededsave: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 13396save: socket bound to port 12612save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: Calling clnttcp_create functionsave: socket bound to port 11598save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 24396save: socket bound to port 23053save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_parms: redirected to ssbak12 prog 390103 vers 2save: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781869save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 28267save: socket bound to port 11838save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 22641save: socket bound to port 19521save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_parms for `nsrstat' succeededsave: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781870save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 19722save: socket bound to port 19190save: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781870save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 20427save: socket bound to port 18894save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 14321save: socket bound to port 14327save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_auth: redirected to ssbak12 prog 390103 vers 2save: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781870save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 18918save: socket bound to port 15136save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 26509save: socket bound to port 13160save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_auth for `nsrd' succeededsave: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 14112save: socket bound to port 25906save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781870save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 21504save: socket bound to port 15064save: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781870save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 21335save: socket bound to port 11857save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 15502save: socket bound to port 23973save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_auth: redirected to ssbak12 prog 390103 vers 2save: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781870save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 23750save: socket bound to port 22691save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 22074save: socket bound to port 17373save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: lgto_auth for `nsrd' succeededsave: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 23474save: socket bound to port 13193save: RPC Authentication: Client successfully authenticated using GSS Legatosave: RPC Authentication: Client successfully authenticated using GSS Legatosave: clu_is_localvirthost:ENTRYsave: input hostname=ssbak12save: clu_is_localvirthost():EXIT unknown cluster typesave: get_myaddrs: cache exist timing, LasTime 1140781868save: get_myaddrs: cache exist timing, CurrTime 1140781871save: Calling clnttcp_create functionsave: Calling clnttcp_create functionsave: socket bound to port 14481save: socket bound to port 17667save: This client is not licensed for VSS.save: getstats(c:	emp, 0011C624)save: fullcanon(name=c:	emp)save: exit fullcanon(fullname=C:	emp)save: lg_lstat(): Calling lgstat().save: ow_get_stats(): stat'ing ASR:\save: ow_find_first_component() called on ASR:\*.*save: ow_get_stats(): stat'ing SYSTEM FILES:\save: ow_find_first_component() called on SYSTEM FILES:\*.*save: ow_find_next_component() called on Extensible Firmware Interface Partitionsave: OW: Extensible Firmware Interface Partition - Returned FALSE for display in GUIsave: ow_get_stats(): stat'ing SYSTEM DB:\save: ow_find_first_component() called on SYSTEM DB:\*.*save: ow_find_next_component() called on Removable Storage Databasesave: ow_find_next_component() called on Windows Management Instrumentation Databasesave: ow_find_next_component() called on Terminal Service Licensing Databasesave: OW: Terminal Service Licensing Database - Returned FALSE for display in GUIsave: ow_find_next_component() called on Content Index Catalogssave: OW: Content Index Catalogs - Returned FALSE for display in GUIsave: ow_get_stats(): stat'ing SYSTEM STATE:\save: ow_find_first_component() called on SYSTEM STATE:\*.*save: GetComputerName: 'UKWAP346'save: call to DsIsNTDSOnline failed, DS not found.save: ow_find_next_component() called on Performance Counterssave: ow_find_next_component() called on Internet Information Servicessave: Metabase, xml file is C:\WINDOWS\system32\inetsrv\MetaBase.xmlsave: ow_find_next_component() called on COM+ Registration Databasesave: ow_find_next_component() called on Certificate Serversave: cert_server_online(): The certificate server is not onlinesave: OW: Certificate Server - Returned FALSE for display in GUIsave: ow_find_next_component() called on Sys Volsave: OW: Sys Vol - Returned FALSE for display in GUIsave: ow_find_next_component() called on Cluster Databasesave: OW: Cluster Database - Returned FALSE for display in GUIsave: ow_find_next_component() called on Registrysave: elogasm_setup_directives: Event Log Directivessave: SYSTEM STATE: AD - SetupDirectives() function not defined!save: SYSTEM STATE: ASRSYSOW - asrsys_setupdirectives: Directivessave: SYSTEM STATE: ASRSYSOW - saved_asr_path is C:\WINDOWSepair\save: SYSTEM STATE: ASRSYSOW - Directives Setupsave: SYSTEM STATE: PCNOW - pcnow_setup_directives: Performance Counter Directivessave: SYSTEM STATE: PCNOW - Directives Setupsave: SYSTEM STATE: IIS - Metabase, xml file is C:\WINDOWS\system32\inetsrv\MetaBase.xmlsave: SYSTEM STATE: IIS - Directives Setupsave: SYSTEM STATE: COMPLUS - SetupDirectives() function not defined!save: SYSTEM STATE: CERT - cert_server_do_directives() calledsave: SYSTEM STATE: CERT - cert_server_online(): The certificate server is not onlinesave: SYSTEM STATE: CERT - Failed to setup directivessave: SYSTEM STATE: SYSVOL - frs_setupdirectives: SYSVOL Directivessave: SYSTEM STATE: SYSVOL - Directives Setupsave: SYSTEM STATE: NTCLUDB - ntcludb_setup_directives: Cluster Directivessave: SYSTEM STATE: NTCLUDB - Directives Setupsave: SYSTEM STATE: REGOW - regow_setup_directives: Registry Directivessave: SYSTEM STATE: REGOW - Directives Setupsave: SYSTEM STATE: - SetupDirectives() succeededsave: SYSTEM DB: QUOOW - quoow_setup_directives: Disk Quota Directivessave: SYSTEM DB: QUOOW - Directives Setupsave: SYSTEM DB: RSMOW - rsmow_setup_directives: RSM database Directivessave: SYSTEM DB: RSMOW - Directives Setupsave: SYSTEM DB: WMI - wmi_db_do_directives() calledsave: SYSTEM DB: WMI - Directives Setupsave: SYSTEM DB: WTSOW - wtsow_setup_directives: WTS database Directivessave: SYSTEM DB: WTSOW - Directives Setupsave: SYSTEM DB: CINDEX - Directives Setupsave: SYSTEM DB: - SetupDirectives() succeededsave: SYSTEM FILES: WPFOW - sfcow_setup_directives: Directivessave: SYSTEM FILES: WPFOW - Directives Setupsave: SYSTEM FILES: WEFIOW - Directives Setupsave: SYSTEM FILES: - SetupDirectives() succeededsave: ASR: ASROW - asr_setup_directives: Directivessave: ASR: ASROW - Directives Setupsave: ASR: - SetupDirectives() succeededsave: win32_pre_save(): Calledsave:cluc_splitsaves(): ENTRY ...save:No -c is specified. save: addss(): ENTRY ... save: clu_pathl_gethost:ENTRY save: input path=c:	emp save: clu_pathl_gethost:EXIT:Clu_cluster_type is undefined save: clu_pathl_free:ENTRY save: clu_pathl_free:EXIT save: clu_is_cluster_host:ENTRY save: clu_is_cluster_host:EXIT:returning FALSE save: clu_is_cluster_host:ENTRY save: clu_is_cluster_host:EXIT:returning FALSE save: clu_is_localvirthost:ENTRY save: input hostname=ssbak12 save: clu_is_localvirthost():EXIT unknown cluster type save: get_myaddrs: cache exist timing, LasTime 1140781868 save: get_myaddrs: cache exist timing, CurrTime 1140781872 save: Calling clnttcp_create function save: Calling clnttcp_create function save: socket bound to port 23104 save: socket bound to port 14049 save: Calling clnttcp_create function save: Calling clnttcp_create function save: socket bound to port 29732 save: socket bound to port 18804 save: RPC Authentication: Client successfully authenticated using GSS Legato save: RPC Authentication: Client successfully authenticated using GSS Legato save: lgto_parms for `nsrmmd' succeeded save: got `store index entries' value of `Yes' save: server enabled for immediate mode save: clu_is_localvirthost:ENTRY save: input hostname=ssbak12 save: clu_is_localvirthost():EXIT unknown cluster type save: lgto_auth for `nsrmmd' succeeded save: Calling clnttcp_create function save: Calling clnttcp_create function save: socket bound to port 20105 save: socket bound to port 10415 save: RPC Authentication: Client successfully authenticated using GSS Legato save: clu_is_localvirthost:ENTRY save: input hostname=ukwbak20.vf-uk.internal.vodafone.com save: clu_is_localvirthost():EXIT unknown cluster type save: get_myaddrs: cache exist timing, LasTime 1140781868 save: get_myaddrs: cache exist timing, CurrTime 1140781872 save: Calling clnttcp_create function save: Calling clnttcp_create function save: socket bound to port 13500 save: socket bound to port 12010 We are seeing some activity on the backup interface but the backup itself just seems to sit there... I'm going to pass this one to EMC to see what they can suggest!

ble1 · Answer

Do you get this only with one client or more than one? What about ftp test? Good luck with 7.3, but it's not going to solve this problem I'm afraid...

DavidHampson · Answer

Hosts tables did not resolve the problem - it remained the same. We looked at the routing tables and the default gateway on the backup network was coming up as the backup interface; we cleared the routing table and then had to restart the server as it dropped off the network

When it rebuilt the routing table we no longer get the "cannot resolve hostname to backup interface IP" message, but now we get as far as it starting to back up a file but just sits there doing nothing!?!

We are going to reinstall the client software to see where that brings us (and upgrade to 7.3)

DavidHampson · Answer

Another update here; we have mapped a drive to ukwap346-bak\c$ from another box and copied data from it - there was no problem, the data copied at a good speed.

ble1 · Answer

One more thing; check netstat -es on the client before and after the test. What is the backup server? If Solaris run snoop for connection toward the client and see what happens. What you are looking for is any kind of drop there might be.

It would be also interesting to see if you can replicate this while nsrexecd on client is running in debug mode (remember something like few years ago where if you would run nsrexecd from cmd on wintel box things would run).

ble1 · Answer

Did you get the access to the client? If yes do following:
- check if you can communicate with your backup server (usual rpcinfo exercise)
- do the ftp session or if ftpd is disabled use scp (pscp.exe from putty package is your friend)
- try to copy something back
- make sure this client is not using some strange server backup interface in resource
- do the manual save in debug mode of one file (yes, I said one file :D) - if that works try directory and then...

You didn't answer if this is for one or more client; if you get the same for more clients (under assumption those clients are not identical build) it is more likely that issue is on server/sn side of the thing. Also, don't forget switch

DavidHampson · Answer

We got a resolution to this one earlier in the week; the issue is down to how Windows handles multiple cards with different gateway settings... Even though the ipconfig info will appear correct the second card will use the gateway of the primary card.

This was resolved by setting the metric on the backup gateway so that it was accessed first.

ble1 · Answer

Interesting to know. Is there any MS Q article on this?

DavidHampson · Answer

I think we finally have a solution to this one. The client has two network connections - a teamed connection to the production LAN (the teamed part being irrelevant) and a connection to the backup LAN. The client is configured with the server network interface of backupserver-bak but actually backs up to a storage node.

You can only set one default gateway on a server - if you want any other traffic to go out via a different gateway you need to configure a static route using the route command:

http://www.microsoft.com/technet/community/columns/cableguy/cg0903.mspx

We had a static route configured for the subnet which the backup server is on; however, it turns out the storage node is on a different subnet which we do not have a static route configured for, so when we send backup data to the storage node it goes out via the default gateway, which is why we were always seeing a backup across the primary interface!

The tracert command was useful here - it confirmed that the backup server interface was being contacted across the correct gateway, but the storage node traffic was going out via the default gateway.

We are carrying out further testing but I think this is our resolution!

DavidHampson · Answer

A word on the metrics response which my colleague came up with, it is not the solution - basically assigning metrics to NICs will ensure that one is more likely to be used than another - for example when you have a high speed and low speed card you want your data to go across the high speed network - it does not force specific traffic across a particular interface!

NetWorker

Very slow backups

Was this post helpful?