BackupPC-users

Re: [BackupPC-users] shadowmountrsync

2013-02-13 21:13:23
Subject: Re: [BackupPC-users] shadowmountrsync
From: <backuppc AT kosowsky DOT org>
To: "General list for user discussion, questions and support" <backuppc-users AT lists.sourceforge DOT net>
Date: Wed, 13 Feb 2013 21:11:34 -0500
Shawn T Perry wrote at about 16:51:32 -0700 on Wednesday, February 13, 2013:
 > On Wed, Feb 13, 2013 at 4:05 PM,  <backuppc AT kosowsky DOT org> wrote:
 > > Shawn T Perry wrote at about 09:27:39 -0700 on Wednesday, February 6, 2013:
 > >> I've followed all the instructions here (
 > >> http://sourceforge.net/apps/mediawiki/backuppc/index.php?title=User_Scripts_-_Client_-_Windows_VSS),
 > >> and when I don't have the script use VSS, it works fine.  However, when I
 > >> turn it on, it sets up everything, but the ssh link doesn't let go,
 > >> allowing backuppc to continue.  What do I need to provide to get some help
 > >> getting this to work?
 > >
 > > Well, it's a bit hard to diagnose given your very generic description
 > > of "ssh link doesn't let go" -- especially since 'ssh link doesn't let
 > > go' is an effect rather than a cause. Unless you have something broken
 > > with ssh, the what you call "link" (actually the shadowmountrsync
 > > command script passed over ssh) will "let go" as soon as the script
 > > terminates. So, we need to figure out why the script is not
 > > terminating.
 > >
 > > Of course, it would helpful if you provide an actual log (with
 > > debugging turned on) for what shadowmountrsync is doing and where it
 > > presumably hangs... that is *why* I wrote the logging -- precisely to
 > > be able to pinpoint failure points. I mean would you expect an auto
 > > mechanic to diagnose your car troubles automatically just by telling
 > > him my "wheel turning things are not moving"
 > >
 > > That being said, if it works without vss, then presumably the problem
 > > is that vss does not return after setting up the shadows. Though of
 > > course without a log it's impossible to know how far VSS proceeds or
 > > even if it is the real culprit or whether it is something before
 > > (e.g., the 'at' bootstrap) or after (launching rsyncd) that causes the
 > > failure. Did I mention a *log* output would be helpful?
 > >
 > > The problem may very well be with your version of vss since Microsoft
 > > in its cleverness includes different functionality and api/command
 > > line interface with almost each different version of MS Windows.  So,
 > > you may need to modify how vss is called from the script (e.g., the
 > > command line parameters) to ensure that vss returns control after
 > > setting up the vshadow mounts. It could also be a problem with
 > > 'dosdev' which is another non-documented and barely supported MS tool
 > > for assigning shadow mounts to drive letters which is required for
 > > some but not all versions of vshadow in order to get user accessible
 > > shadow drives...
 > >
 > > Did I mention a *log* output would be HELPFUL?
 > >
 > 
 > [02/13/13 16:35:48]
 > [4036|996][svc_autobackup||svc_autobackup|svc_autobackup]
 > /usr/local/bin/shadowmountrsync -u 1 -A 3 [Pass #1]
 > ***Initial pass through (PID=996)...[Pass #1]
 > ..Finished clean_up... [Pass #1]
 > --Starting ACL backup for volumes: E: [Pass #1]
 > ..Finished ACL backup for volumes: E: [Pass #1]
 > --Relaunching via 'cmd.exe'...[Pass #1]
 > --Initial pass going into background waiting for setup to complete...[Pass 
 > #1]
 > 
 > [02/13/13 16:35:58]
 > [1|3600][svc_autobackup||svc_autobackup|svc_autobackup]
 > /usr/local/bin/shadowmountrsync -2 -u 1 -A 3 [Pass #2]
 > **Running inital shadow setup (PID=3600)...[Pass #2]
 > --Starting shadow copy and waiting for 'exec' script to terminate...[Pass #2]
 > 
 > C:\cygwin\home\svc_autobackup>REM Shadowexec.cmd
 > 
 > C:\cygwin\home\svc_autobackup>REM Version 0.4.5 (November 2009)
 > 
 > C:\cygwin\home\svc_autobackup>REM This cmd.exe script file should be
 > in the same directory as the
 > 
 > C:\cygwin\home\svc_autobackup>REM bash script: shadowmountrsync
 > 
 > [02/13/13 16:36:09]
 > [1|3364][svc_autobackup||svc_autobackup|svc_autobackup]
 > /usr/local/bin/shadowmountrsync -3 -2 -u 1 -A 3 [Pass #3]
 > **Running exec command spawned by vshadow (PID=3364)...[Pass #3]
 > ..Drive letters=Z   [Pass #3]
 > ..Shadow mounts=E:   [Pass #3]
 >     Z:->E:  \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy7
 >         Z: on /shadow/Z type ntfs (binary,user)
 > --Starting rsyncd daemon (with shadow mounts) and waiting for file
 > transfer to complete...[Pass #3]
 > ..Rsyncd Params: Conf=/shadow/rsyncd.shadow.conf Address= Port=
 > BWLimit= Other=...[Pass #3]
 > ..Rsyncd started successfully (PID=216)...[Pass #1]
 > 
 > 
 > It hangs here.
 > 
 > rsync is running:
 > 
 > $ rsync rsync://localhost
 > e
 > 
 > 
 > 
 > If I kill the newest sshd, it backups up perfectly.  This is the log
 > after I kill it.
 > 
 > 
 > 
 > [02/13/13 16:35:58]
 > [1|3600][svc_autobackup||svc_autobackup|svc_autobackup]
 > /usr/local/bin/shadowmountrsync -2 -u 1 -A 3 [Pass #2]
 > **Running inital shadow setup (PID=3600)...[Pass #2]
 > --Starting shadow copy and waiting for 'exec' script to terminate...[Pass #2]
 > 
 > C:\cygwin\home\svc_autobackup>REM Shadowexec.cmd
 > 
 > C:\cygwin\home\svc_autobackup>REM Version 0.4.5 (November 2009)
 > 
 > C:\cygwin\home\svc_autobackup>REM This cmd.exe script file should be
 > in the same directory as the
 > 
 > C:\cygwin\home\svc_autobackup>REM bash script: shadowmountrsync
 > 
 > VSHADOW.EXE 2.2 - Volume Shadow Copy sample client
 > Copyright (C) 2005 Microsoft Corporation. All rights reserved.
 > 
 > 
 > (Option: Execute binary/script after shadow creation
 > 'C:\cygwin\usr\local\bin\shadowexec.cmd')
 > (Option: Create shadow copy set)
 > (Gathering writer metadata...)
 > (Waiting for the asynchronous operation to finish...)
 > Initialize writer metadata ...
 > Discover directly excluded components ...
 > - Excluding writer 'MSDEWriter' since it has no selected components for 
 > restore.
 > Discover components that reside outside the shadow set ...
 > - Component '\System Files' from writer 'System Writer' is excluded
 > from backup (it requires C:\ in the shadow set)
 > - Component '\Event Logs' from writer 'Event Log Writer' is excluded
 > from backup (it requires C:\ in the shadow set)
 > - Component '\COM+ REGDB' from writer 'COM+ REGDB Writer' is excluded
 > from backup (it requires C:\ in the shadow set)
 > - Component '\Registry' from writer 'Registry Writer' is excluded from
 > backup (it requires C:\ in the shadow set)
 > - Component '\WMI' from writer 'WMI Writer' is excluded from backup
 > (it requires C:\ in the shadow set)
 > Discover all excluded components ...
 > Discover excluded writers ...
 > - The writer 'System Writer' is now entirely excluded from the backup:
 >   (it does not contain any components that can be potentially included
 > in the backup)
 > - The writer 'Event Log Writer' is now entirely excluded from the backup:
 >   (it does not contain any components that can be potentially included
 > in the backup)
 > - The writer 'COM+ REGDB Writer' is now entirely excluded from the backup:
 >   (it does not contain any components that can be potentially included
 > in the backup)
 > - The writer 'Registry Writer' is now entirely excluded from the backup:
 >   (it does not contain any components that can be potentially included
 > in the backup)
 > - The writer 'WMI Writer' is now entirely excluded from the backup:
 >   (it does not contain any components that can be potentially included
 > in the backup)
 > Discover explicitly included components ...
 > Verifying explicitly specified writers/components ...
 > Select explicitly included components ...
 > Creating shadow set {d706c62f-0234-404a-9076-3eaf3fe43e8a} ...
 > - Adding volume \\?\Volume{7d2447b5-6cbb-11e2-ab18-000c297bd574}\
 > [E:\] to the shadow set...
 > Preparing for backup ...
 > (Waiting for the asynchronous operation to finish...)
 > (Waiting for the asynchronous operation to finish...)
 > Creating the shadow (DoSnapshotSet) ...
 > (Waiting for the asynchronous operation to finish...)
 > (Waiting for the asynchronous operation to finish...)
 > Shadow copy set succesfully created.
 > 
 > List of created shadow copies:
 > 
 > 
 > Querying all shadow copies with the SnapshotSetID
 > {d706c62f-0234-404a-9076-3eaf3fe43e8a} ...
 > 
 > * SNAPSHOT ID = {194c40ce-bd6e-4c62-9434-beb163af4863} ...
 >    - Shadow copy Set: {d706c62f-0234-404a-9076-3eaf3fe43e8a}
 >    - Original count of shadow copies = 1
 >    - Original Volume name:
 > \\?\Volume{7d2447b5-6cbb-11e2-ab18-000c297bd574}\ [E:\]
 >    - Creation Time: 2/13/2013 4:36:04 PM
 >    - Shadow copy device name: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy7
 >    - Originating machine: backuptestserver.KIS-KIOSK.COM
 >    - Service machine: backuptestserver.KIS-KIOSK.COM
 >    - Not Exposed
 >    - Provider id: {b5946137-7b9f-4925-af80-51abd60b20d5}
 >    - Attributes:  Auto_Release Differential
 > 
 > - Executing command 'C:\cygwin\usr\local\bin\shadowexec.cmd' ...
 > -----------------------------------------------------
 > -----------------------------------------------------
 > ERROR: Command line '"C:\cygwin\usr\local\bin\shadowexec.cmd"'
 > failed!. Aborting the backup...
 > - Returned error code: 3840
 > - Backup failed. Mark all writers as not succesfully backed up...
 > Completing the backup (BackupComplete) ...
 > (Waiting for the asynchronous operation to finish...)
 > (Waiting for the asynchronous operation to finish...)
 > --Vshadow terminated: cleaning up...[Pass #2]
 > ..Finished clean_up... [Pass #2]
 > [02/13/13 16:44:06] Done! Clean up completed...[Pass #2]
 > 
 > --Successfully unwound shadow recursion...[Pass #0]
 > --Termination completed...[Pass #0]
 > 
 > 
 > 
 > Please let me know if I need to provide more info to help.

Well, it's a bit confusing since you seem to be mixing the log file
with stuff from your console...

But shadowmountrsync does seem to be running successfully, launching
the appropriate vss, dosdev & rsyncd apps and then unwinding the
recursion and (presumably) exiting with exit code 0.

First, what version of shadowmountrsync are you using?
My latest version (0.4.8) has some neat features like passing back the rsyncd
secret so it doesn't have to be stored in the config file... though it
requires some perl magic in the config file and a patch to a bug in
backuppc....

Second, what ssh string are you using in the config file for DumpPreUserCmd?

To troubleshoot, I would try doing the following:
First, run shadowmountrsync *directly* on the client from say a cygwin
terminal:
                /usr/local/bin/shadowmountrsync -u 1 -A 3
Check that it runs, sets up the shadow mounts, associates the drive
letters, launches rsyncd, and TERMINATES. Check the exit code (echo
$?)

Then try running it from your server using the ssh command (without
BackupPC).
e.g.,
        ssh -q -x -l user@client "/usr/local/bin/shadowmountrsync -u 1 -A 3"

Again check your client to see what is happening the log and that the
above behaviors all occur properly. See if the ssh call terminates
(which it should if the shadowmountrsync script terminates). If it
does, see what shadowmountrsync returns by checking the ssh exit code
(echo $?)

If you want to shortcut the generating of ACLs for testing purposes,
use "-A 0"

You can also try adding "set +x" in shadowmountrsync to see how each
line is parsed...

Hope this helps

------------------------------------------------------------------------------
Free Next-Gen Firewall Hardware Offer
Buy your Sophos next-gen firewall before the end March 2013 
and get the hardware for free! Learn more.
http://p.sf.net/sfu/sophos-d2d-feb
_______________________________________________
BackupPC-users mailing list
BackupPC-users AT lists.sourceforge DOT net
List:    https://lists.sourceforge.net/lists/listinfo/backuppc-users
Wiki:    http://backuppc.wiki.sourceforge.net
Project: http://backuppc.sourceforge.net/