Add --debug flag, and make --verbose less verbose about debug info

Trim whitespace on all arguments (due to docker-compose.yml oddities)
Upgrade test/docker-compose.yml to version 2 format
Fix bug, primary command was running after a --run command failed.

.gitignore

@@ -4,3 +4,4 @@ build/*
 .DS_Store
 .dockerfy*
 .python-version
+/blurbs/

README.md

@@ -133,7 +133,6 @@ If the source path ends with a /, then all subdirectories underneath it will be
 
 Overlay sources that do not exist are simply skipped.  The allows you to specify potential sources of content that may or may not exist in the running container.  In the above example if $DEPLOYMENT_ENV environment variable is set to 'local' then the second overlaw will be skipped if there is no corresponding /app/overlays/local source directory, and the container will run with the '_common' html content.
 
-
 #### Loading Secret Settings
 Secrets can loaded from a file by using the `--secrets-files` option or the $SECRETS_FILES environment variable.   The secrets files ending with `.env` must contain simple NAME=VALUE lines, following bash shell conventions for definitions and comments. Leading and trailing quotes will be trimmed from the value.  Secrets files ending with `.json` will be loaded as JSON, and must be `a simple single-level dictionary of strings`
 
@@ -278,6 +277,11 @@ The `--start` option gives you the opportunity to start a commands as a service
 All options up to but not including the '--' will be passed to the command.  You can start as many services as you like, they will all be started in the same order as how they were provided on the command line, and all commands must continue **successfully** or **dockerfy** will
 stop your primary command and exit, and the container will stop.
 
+#### Debugging Dockerfy
+If dockerfy isn't behaving as you expect, then try the `--debug` flag to view more detailed debugging output, including details about how `--run` and `--start` commands are processed.
+
+NOTE: The `--debug` flag is discouraged in production because it will leak the names of secrets variables to the logs
+
 ### Switching User Accounts
 The `--user` option gives you the ability specify which user accounts with which to run commands or start services.  The `--user` flag takes either a username or UID as its argument, and affects all subsequent commands.
 

args.go

@@ -31,35 +31,46 @@ func removeCommandsFromOsArgs() Commands {
 	var cmd *exec.Cmd
 	var cmd_user *user.User
 
+    if debugFlag {
+        log.Printf("")
+        log.Printf("dockerfy args BEFORE removing commands:\n")
+
+        for i := 0; i < len(os.Args); i++ {
+            log.Printf("\t%d: %s", i, os.Args[i])
+        }
+    }
+
 	for i := 0; i < len(os.Args); i++ {
+        // docker-compose.yml files are buggy on \ continuation characters
+        arg_i := strings.TrimSpace(os.Args[i])
 		switch {
-		case ("--start" == os.Args[i] || "-start" == os.Args[i]) && cmd == nil:
+		case ("--start" == arg_i || "-start" == arg_i) && cmd == nil:
 			cmd = &exec.Cmd{Stdout: os.Stdout,
 				Stderr:      os.Stderr,
 				SysProcAttr: &syscall.SysProcAttr{Credential: commands.credential}}
 			commands.start = append(commands.start, cmd)
 
-		case ("--run" == os.Args[i] || "-run" == os.Args[i]) && cmd == nil:
+		case ("--run" == arg_i || "-run" == arg_i) && cmd == nil:
 			cmd = &exec.Cmd{Stdout: os.Stdout,
 				Stderr:      os.Stderr,
 				SysProcAttr: &syscall.SysProcAttr{Credential: commands.credential}}
 			commands.run = append(commands.run, cmd)
 
-		case ("--user" == os.Args[i] || "-user" == os.Args[i]) && cmd == nil:
+		case ("--user" == arg_i || "-user" == arg_i) && cmd == nil:
 			if os.Getuid() != 0 {
 				log.Fatalf("dockerfy must run as root to use the --user flag")
 			}
 			cmd_user = &user.User{}
 
-		case "--" == os.Args[i] && cmd != nil: // End of args for this cmd
+		case "--" == arg_i && cmd != nil: // End of args for this cmd
 			cmd = nil
 
 		default:
 			if cmd_user != nil {
 				// Expect a username or uid
 				var err1 error
 
-				user_name_or_id := os.Args[i]
+				user_name_or_id := arg_i
 				cmd_user, err1 = user.LookupId(user_name_or_id)
 				if cmd_user == nil {
 					// Not a userid, try as a username
@@ -79,14 +90,14 @@ func removeCommandsFromOsArgs() Commands {
 			} else if cmd != nil {
 				// Expect a command first, then a series of arguments
 				if len(cmd.Path) == 0 {
-					cmd.Path = os.Args[i]
+					cmd.Path = arg_i
 					if filepath.Base(cmd.Path) == cmd.Path {
 						cmd.Path, _ = exec.LookPath(cmd.Path)
 					}
 				}
-				cmd.Args = append(cmd.Args, os.Args[i])
+				cmd.Args = append(cmd.Args, arg_i)
 			} else {
-				newOsArgs = append(newOsArgs, os.Args[i])
+				newOsArgs = append(newOsArgs, arg_i)
 			}
 		}
 	}
@@ -97,6 +108,16 @@ func removeCommandsFromOsArgs() Commands {
 		log.Fatalf("need a command after the --start or --run flag")
 	}
 	os.Args = newOsArgs
+
+    if debugFlag {
+        log.Printf("")
+        log.Printf("dockerfy args AFTER removing commands:\n")
+
+        for i := 0; i < len(os.Args); i++ {
+            log.Printf("\t%d: %s", i, os.Args[i])
+        }
+    }
+
 	return commands
 }
 

dockerfy.go

@@ -50,7 +50,8 @@ var (
 	stdoutTailFlag       sliceVar
 	templatesFlag        sliceVar
 	usersFlag            sliceVar
-	verboseFlag          bool
+    verboseFlag          bool
+    debugFlag            bool
 	versionFlag          bool
 	waitFlag             hostFlagsVar
 	waitTimeoutFlag      time.Duration
@@ -151,14 +152,24 @@ func main() {
 	flag.Var(&runsFlag, "run", "run (cmd [opts] [args] --) Can be passed multiple times")
 	flag.Var(&startsFlag, "start", "start (cmd [opts] [args] --) Can be passed multiple times")
 	flag.BoolVar(&reapFlag, "reap", false, "reap all child processes")
-	flag.BoolVar(&verboseFlag, "verbose", false, "verbose output")
+    flag.BoolVar(&verboseFlag, "verbose", false, "verbose output")
+    flag.BoolVar(&debugFlag, "debug", false, "debugging output")
 	flag.Var(&stdoutTailFlag, "stdout", "Tails a file to stdout. Can be passed multiple times")
 	flag.Var(&stderrTailFlag, "stderr", "Tails a file to stderr. Can be passed multiple times")
 	flag.StringVar(&delimsFlag, "delims", "", `template tag delimiters. default "{{":"}}" `)
 	flag.Var(&waitFlag, "wait", "Host (tcp/tcp4/tcp6/http/https) to wait for before this container starts. Can be passed multiple times. e.g. tcp://db:5432")
 	flag.DurationVar(&waitTimeoutFlag, "timeout", 10*time.Second, "Host wait timeout duration, defaults to 10s")
 	flag.DurationVar(&reapPollIntervalFlag, "reap-poll-interval", 120*time.Second, "Polling interval for reaping zombies")
 
+    // Manually pre-process the --debug flag so we can debug our removeCommandsFromOsArgs which happens BEFORE
+    // we call flag.Parse()
+    for i := 0; i < len(os.Args); i++ {
+        if os.Args[i] == "--debug" {
+            debugFlag = true
+            log.Printf("debugging output ..")
+        }
+    }
+
 	var commands = removeCommandsFromOsArgs()
 
 	flag.Usage = usage
@@ -189,6 +200,9 @@ func main() {
 
 	// Overlay files from src --> dst
 	for _, o := range overlaysFlag {
+        if debugFlag {
+            log.Printf("--overlay: %s", o)
+        }
 		if strings.Contains(o, ":") {
 			parts := strings.Split(o, ":")
 			if len(parts) != 2 {
@@ -259,7 +273,10 @@ func main() {
 			}
 		}, cmd, false /*cancel_when_finished*/)
 		wg.Wait()
-		log.Printf("ready for next cmd")
+        if exitCode != 0 {
+            cancel()
+            os.Exit(exitCode)
+        }
 	}
 
 	for _, logFile := range stdoutTailFlag {

exec.go

@@ -32,6 +32,9 @@ func runCmd(ctx context.Context, cancel context.CancelFunc, cmd *exec.Cmd, cance
 		// TODO: bubble the platform-specific exit code of the process up via global exitCode
 		log.Fatalf("Error starting command: `%s` - %s\n", toString(cmd), err)
 	}
+    if debugFlag && cmd.SysProcAttr != nil && cmd.SysProcAttr.Credential != nil {
+        log.Printf("command running as uid %d", cmd.SysProcAttr.Credential.Uid)
+    }
 
 	// Setup signaling -- a separate channel for goroutine for each command
 	sigs := make(chan os.Signal, 1)
@@ -42,7 +45,7 @@ func runCmd(ctx context.Context, cancel context.CancelFunc, cmd *exec.Cmd, cance
 		defer wg.Done()
 		select {
 		case sig := <-sigs:
-			if verboseFlag {
+			if debugFlag {
 				if sig != nil {
 					log.Printf("Command `%s` received signal", toString(cmd))
 				} else {
@@ -51,7 +54,7 @@ func runCmd(ctx context.Context, cancel context.CancelFunc, cmd *exec.Cmd, cance
 			}
 			//cancel()
 		case <-ctx.Done():
-			if verboseFlag {
+			if debugFlag {
 				log.Printf("Command `%s` done waiting for signals (ctx.Done())", toString(cmd))
 			}
 			signalProcessWithTimeout(cmd, syscall.SIGTERM)

secrets.go

@@ -114,9 +114,9 @@ func getSecrets() map[string]string {
 				}
 				key, value := parts[0], strings.Trim(strings.TrimSpace(parts[1]), `'"`)
 				secrets[key] = value
-				//if verboseFlag {
-				//	log.Printf("loaded secret: %s", key)
-				//}
+				if debugFlag {
+					log.Printf("loaded secret: %s", key)
+				}
 			}
 		} else if strings.HasSuffix(secretsFileName, ".json") {
 			jsonData, err := ioutil.ReadAll(secretsFile)
@@ -129,9 +129,9 @@ func getSecrets() map[string]string {
 			}
 			for key, value := range secrets {
 				secrets[key] = value
-				//if verboseFlag {
-				//	log.Printf("loaded secret: %s", key)
-				//}
+				if debugFlag {
+					log.Printf("loaded secret: %s", key)
+				}
 			}
 		} else {
 			log.Fatalf("Unknown file extension '%s' must end with .env or .json\n", secretsFileName)

test/Makefile

@@ -151,7 +151,7 @@ run-fails-before-primary-test:
 	@echo "################################################################################"
 	@docker rm -f test-nginx >/dev/null 2>&1 || true
 
-	docker run -it --name test-nginx nginx-with-dockerfy-and-zombie-maker --verbose \
+	docker run -it --name test-nginx nginx-with-dockerfy-and-zombie-maker --verbose --debug \
 		--run bash -c 'echo "RUN COMMAND FAILED"; exit 1' -- \
 		bash -c "echo 'PRIMARY COMMAND DONE'" >/dev/null 2>&1 || true
 	docker logs test-nginx 2>&1 | egrep -q '^RUN COMMAND FAILED'
@@ -193,15 +193,22 @@ run-user-option-test:
 	@echo "################################################################################"
 	docker run -it -e SECRETS_FILES=/secrets/secrets.json:/secrets/secrets.2.json \
 	    --name test-nginx nginx-with-dockerfy-and-zombie-maker \
-		--run echo -n "MAIL:" -- --user mail  --run id -a -- \
-		--run ls -l '/var/spool/mail/.secrets' -- \
-		--run cat '/var/spool/mail/.secrets/combined_secrets.json' -- \
-		--run cat '/var/spool/mail/.secrets/secrets.json' -- \
-		--run /usr/bin/env -- \
-		--run echo -n "ROOT:" -- --user root  --run id -a -- \
-		--run /usr/bin/env -- \
-		--run echo -n "PRIMARY:" -- \
-		id -a >/dev/null 2>&1
+	    --debug \
+		\
+		--user mail \
+			--run echo -n "MAIL:" -- \
+		 	--run id -a -- \
+			--run ls -l '/var/spool/mail/.secrets' -- \
+			--run cat '/var/spool/mail/.secrets/combined_secrets.json' -- \
+			--run cat '/var/spool/mail/.secrets/secrets.json' -- \
+			--run /usr/bin/env -- \
+		\
+		--user root \
+			--run echo -n "ROOT:" -- \
+			--run id -a -- \
+			--run /usr/bin/env -- \
+			--run echo -n "PRIMARY:" -- \
+			id -a >/dev/null 2>&1
 	docker logs test-nginx 2>/dev/null| egrep -q -- '\-r\-* .*secrets.json'
 
 	docker logs test-nginx 2>/dev/null| fgrep -q -- 'SECRETS_FILE=/var/mail/.secrets/combined_secrets.json'
@@ -211,7 +218,6 @@ run-user-option-test:
 	docker logs test-nginx 2>/dev/null| fgrep -q -- '"JSON_SECRET": "Jason Voorhees did it"'
 	[ $$(docker logs test-nginx 2>/dev/null| fgrep -- 'uid=0(root) gid=0(root) groups=0(root)' | wc -l) == 2 ]
 	# '
-	@docker rm -f test-nginx >/dev/null 2>&1 || true
 	@echo "run-user-option-test PASSED"
 
 run-option-expansion-test:

test/docker-compose.yml

@@ -1,21 +1,24 @@
 #
 #  docker-compose file to run the equivalient of the Makefile target 'run-prod-secrets'
 #
-nginx-with-dockerfy:
-  image: markriggins/nginx-with-dockerfy
-
-  volumes:
-    - $PWD:/secrets
-
-  environment:
-    - SECRETS_FILES=/secrets/secrets.env
-
-  entrypoint:
-    - dockerfy
+version: '2'
 
-  command: [ 
-    '-overlay', '/tmp/overlays/_common/:/usr/share/nginx/',
-    '-overlay', '/tmp/overlays/{{ .Env.DEPLOYMENT_ENV }}/html:/usr/share/nginx/',
-    '-template', '/secrets/secrets.html.tmpl:/usr/share/nginx/html/secrets.html',
-    '--', 'nginx' ]
+services:
+  nginx-with-dockerfy:
+    image: nginx-with-dockerfy
+
+    volumes:
+      - $PWD:/secrets
+
+    environment:
+      - SECRETS_FILES=/secrets/secrets.env
+      - DEPLOYMENT_ENV=staging
+      - DOCKERFY_DEBUG=1
+
+    entrypoint: dockerfy
+
+    command: --verbose --debug --overlay /tmp/overlays/_common/:/usr/share/nginx \
+      --overlay '/tmp/overlays/{{ .Env.DEPLOYMENT_ENV }}/html:/usr/share/nginx/' \
+      --template '/secrets/secrets.html.tmpl:/usr/share/nginx/html/secrets.html' \
+      -- nginx