Sync bonus round: sync:name, sync:purge, sync:check #165

grayside · 2018-03-15T21:18:30Z

This set of changes got just tangled enough that I've kept them together. If the time to separate them seems worth doing please say so and I'll take care of it.

Please note this is still a work in progress, and is shared now for context to ongoing unison discussions.

This PR adds the following:

rig project sync:name to facilitate scripting against a project's unison container and volume.
rig project sync:purge to clean up/zero out the file sync for a clean slate restart.
rig project sync:check is a doctor check for unison. I'm not sure I want to use doctor, but that might happen. The goals of this are outlined more in Detect unison failure: unison doctor command? #163.

I've also done some light refactoring to cleanup/streamline the sync code.

Fixes #163

* origin/develop: Refactor project scripts into cleaner API. (#157) Create 'rig ssh' command (#159)

tekante · 2018-04-10T02:01:22Z

commands/project_sync.go

+	if err != nil {
+		fmt.Println(string(out))
+		fmt.Println(err.Error())
+		return cmd.Failure(string(out), "SYNC-VOLUME-FAILURE", 13)


I seem to always hit this condition. Here is a quick test script that always fails from me. It is set up to run from the rig project directory and use a locally built version of rig.

#!/bin/bash set -e DIR=purgetest mkdir -p $DIR ./build/darwin/rig --verbose project sync:start --dir=$DIR ./build/darwin/rig --verbose project sync:stop --dir=$DIR ./build/darwin/rig --verbose project sync:purge --dir=$DIR

I'll note the underlying command that the --verbose flag causes to spit out seems to run without error and the return code when it finishes is 0. Perhaps it has something to do with tie-ing the out/err file handles together

Doing some experimenting it is the file handle tie-ing that is causing the issue. If I remove that part of the argument and remove the print of out in the case where the command succeeds it seems to run quietly which is what I thought the intention was.

Here is the diff that I tested.

diff --git a/commands/project_sync.go b/commands/project_sync.go index ddfbee6..f27177b 100644 --- a/commands/project_sync.go +++ b/commands/project_sync.go @@ -278,13 +278,12 @@ func (cmd *ProjectSync) RunPurge(ctx *cli.Context) error { cmd.out.Spin(fmt.Sprintf("Removing sync volume: %s", volumeName)) // @TODO capture the volume rm error text to display to user! - out, err := util.Command("docker", "volume", "rm", volumeName, "1>&2").Output() + out, err := util.Command("docker", "volume", "rm", volumeName).Output() if err != nil { fmt.Println(string(out)) fmt.Println(err.Error()) return cmd.Failure(string(out), "SYNC-VOLUME-FAILURE", 13) } - fmt.Println(string(out)) return nil }

I get the panic too. Instead of Output() we likely just need to use CombinedOutput() will check that this makes the panic go away.

tekante · 2018-04-10T02:05:44Z

commands/project_sync.go

+
+	// Remove sync fragment files.
+	cmd.out.Spin("Removing .unison directories")
+	if err := util.RemoveFileGlob("*.unison*", workingDir, cmd.out); err != nil {


I don't have a lot of experience with these fragment directories. Do both the directory names and all the files within them match the .unison pattern (which I believe they would need to in order for this cleanup to succeed).

I tested this with various files, here's an example:

.unison.._.DS_Store.94df3249bac7c3ee51c590d510133947.unison.tmp

I could not remember if I'd see something prefixing .unison so went ahead to cover both.

tekante · 2018-04-10T02:15:43Z

Other than the notes I left with some questions and concerning the purge not seeming to work overall I think this is looking pretty good to me.

febbraro · 2018-04-20T04:41:03Z

@grayside I addresses a few things I saw in my review. I'm approving this, but wanted you to see the changes in case I changed any assumptions you had. Feel free to merge, or approve the additions and I can handle it.

potterme · 2018-04-20T12:29:45Z

Not a golang expert and not set up to test this, but I like the new commands and the basic logic seems good. Also the pattern for purge cleanup looks good. I have several files right now on my local:

.unison.icons.eot.1e3f49a97047f0a8175c6ea7781ef5da.unison.tmp
.unison.._.DS_Store.f22e592b2ce5945c749e57f21f951e3a.unison.tmp

The DS_Store ones are the most common.

grayside · 2018-04-20T16:00:03Z

I left the name here as rig project sync:check, do we feel like it should be verify for slightly more semantic context, or doctor for alignment with rig doctor?

febbraro · 2018-04-20T17:04:02Z

check or verify work for me. I think if we call it doctor we would actually introduce confusion,

Us: "Have you run doctor"
Users: "Which one?"

tekante · 2018-04-23T02:15:11Z

Note that I'm still seeing some issues on the purge command but I don't think they are significant enough to hold up things since they revolve around the unison cleanup.

Test script designed to be run from within the root of the repo after doing a build:

#!/bin/bash

set -e
#VERBOSE=''
VERBOSE=--verbose
DIR=purgetest
mkdir -p $DIR

#./build/darwin/rig --verbose project sync:start --dir=$DIR
#./build/darwin/rig --verbose project sync:stop --dir=$DIR
#./build/darwin/rig --verbose project sync:purge --dir=$DIR

grep version examples/outrigger.example.yml > $DIR/outrigger.yml

pushd $DIR
../build/darwin/rig $VERBOSE project sync:start

touch .unison.icons.eot.1e3f49a97047f0a8175c6ea7781ef5da.unison.tmp
touch .unison.._.DS_Store.f22e592b2ce5945c749e57f21f951e3a.unison.tmp

sleep 2
../build/darwin/rig $VERBOSE project sync:stop
../build/darwin/rig $VERBOSE project sync:purge

First issue I encountered appears to be a duplication of the base directory. Second is an lstat command failing that I haven't tracked down.

Here is diff output that allows for some additional debugging (and avoids the duplicate base directory issue though I haven't fully tested it yet.

diff --git a/commands/project_sync.go b/commands/project_sync.go
index 077ccaa..a81eabb 100644
--- a/commands/project_sync.go
+++ b/commands/project_sync.go
@@ -270,7 +270,7 @@ func (cmd *ProjectSync) RunPurge(ctx *cli.Context) error {
        // Remove sync fragment files.
        cmd.out.Spin("Removing .unison directories")
        if err := util.RemoveFileGlob("*.unison*", workingDir, cmd.out); err != nil {
-               cmd.out.Warning("Could not remove .unison directories")
+               cmd.out.Warning("Could not remove .unison directories: %s", err)
        } else {
                cmd.out.Info("Removed all .unison directories")
        }
diff --git a/util/filesystem.go b/util/filesystem.go
index 3abb5ea..edb5ca6 100644
--- a/util/filesystem.go
+++ b/util/filesystem.go
@@ -16,6 +16,9 @@ func GetExecutableDir() (string, error) {
 // AbsJoin joins the two path segments, ensuring they form an absolute path.
 func AbsJoin(baseDir, suffixPath string) (string, error) {
        absoluteBaseDir, err := filepath.Abs(baseDir)
+       if (baseDir == "" ) {
+               absoluteBaseDir = ""
+       }
        if err != nil {
                return "", fmt.Errorf("Unrecognized working directory: %s: %s", baseDir, err.Error())
        }
@@ -61,6 +64,7 @@ func RemoveFileGlob(glob, targetDirectory string, logger *RigLogger) error {
                                        }

                                        if removeErr := RemoveFile(file, ""); removeErr != nil {
+                                               logger.Verbose("Remove error '%s'", removeErr)
                                                return removeErr
                                        }
                                }

grayside · 2018-05-18T00:03:17Z

I found and address the double basepath, added some more verbose logging, and added a debug log message where I found the lstat error is throwing: just inside the callback for the filepath.Walk().

To reproduce this error run these commands:

touch .unison
./build/darwin/rig --verbose project sync:purge

This will output the following:

[VERBOSE] Executing: /usr/local/bin/docker ps -aq --filter name=^/rig3-sync ()
[VERBOSE] Executing: /usr/local/bin/docker top  ()
[INFO] No running unison container.
[INFO] Log file does not exist
[VERBOSE] Removing file '/Users/aross/Projects/Outrigger/rig3/.unison'...
[VERBOSE] This is the first err: lstat /Users/aross/Projects/Outrigger/rig3/.unison: no such file or directory
[WARN] Could not remove .unison directories: lstat /Users/aross/Projects/Outrigger/rig3/.unison: no such file or directory
[VERBOSE] Executing: /usr/local/bin/docker volume rm --force rig3-sync ()
[INFO] Sync volume (rig3-sync) removed

Despite the error, the process successfully removes our .unison file.

So what could be going wrong? The file it's complaining about is not a symlink. If I create the file with echo "some content" > .unison the result is the same.

After studying this, my theory is:

When the filepath.Walk() dispatches to the callback, it first cycles through stat/lstat/etc trying to find a successful way to pull metadata
filepath.Walk() first enumerates all the files in a directory (maybe it's async) then dispatches to process each file/directory. However, we are sometimes removing files. When the callback gets to a removed file it stumbles into first situation.

In order to fix that, we need to either keep track of the files removed and ignore them when they throw this specific error... or ignore errors on this because honestly it's a nice to have. Working on the latter, just a minute.

febbraro · 2018-05-18T13:45:38Z

Awesome, thanks for all the hard work @grayside

Adam Ross added 2 commits March 15, 2018 13:58

Add sync:name, sync:purge, sync:check WIP

c69b3e7

Additional cleanup of unison file purge.

751ca45

grayside requested review from tekante, febbraro and mike-potter March 15, 2018 21:18

Adam Ross added 3 commits March 26, 2018 15:49

Merge remote-tracking branch 'origin/develop' into sync-bonus-round

3377de5

* origin/develop: Refactor project scripts into cleaner API. (#157) Create 'rig ssh' command (#159)

Correct lint errors.

c58fbe6

Cannot forget the go formatting

677b11b

tekante reviewed Apr 10, 2018

View reviewed changes

febbraro added 2 commits April 19, 2018 21:15

Fixed undefined reference to an error

6737e7b

fixed output redirection and logging

6f659d6

febbraro approved these changes Apr 20, 2018

View reviewed changes

tekante approved these changes Apr 23, 2018

View reviewed changes

grayside changed the title ~~Sync bonus round: sync:name, sync:purge, sync:check [WIP]~~ Sync bonus round: sync:name, sync:purge, sync:check Apr 25, 2018

Fix double basepath and start troubleshooting lstat

25ab370

Adam Ross added 2 commits May 17, 2018 17:06

Fix stray lstat warning.

044bc97

Fix lint errors.

2b70495

febbraro merged commit 94f67da into develop May 18, 2018

febbraro deleted the sync-bonus-round branch May 18, 2018 13:45

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Sync bonus round: sync:name, sync:purge, sync:check #165

Sync bonus round: sync:name, sync:purge, sync:check #165

grayside commented Mar 15, 2018

tekante Apr 10, 2018

tekante Apr 10, 2018

tekante Apr 16, 2018

febbraro Apr 20, 2018

tekante Apr 10, 2018

grayside Apr 13, 2018

tekante commented Apr 10, 2018

febbraro commented Apr 20, 2018

potterme commented Apr 20, 2018

grayside commented Apr 20, 2018

febbraro commented Apr 20, 2018

tekante commented Apr 23, 2018

grayside commented May 18, 2018

febbraro commented May 18, 2018

Sync bonus round: sync:name, sync:purge, sync:check #165

Sync bonus round: sync:name, sync:purge, sync:check #165

Conversation

grayside commented Mar 15, 2018

tekante Apr 10, 2018

Choose a reason for hiding this comment

tekante Apr 10, 2018

Choose a reason for hiding this comment

tekante Apr 16, 2018

Choose a reason for hiding this comment

febbraro Apr 20, 2018

Choose a reason for hiding this comment

tekante Apr 10, 2018

Choose a reason for hiding this comment

grayside Apr 13, 2018

Choose a reason for hiding this comment

tekante commented Apr 10, 2018

febbraro commented Apr 20, 2018

potterme commented Apr 20, 2018

grayside commented Apr 20, 2018

febbraro commented Apr 20, 2018

tekante commented Apr 23, 2018

grayside commented May 18, 2018

febbraro commented May 18, 2018