fix(transparent-proxy): stop logging all to stderr when installing tp…

…roxy (#10045)

Because of the construction of the log line, where everything was
located at the same line, we were not able to figure out at the
beginnig of the log if it'll be successfull or not, so everything
was logged in stderr. It's wrong when you have a monitoring set
to watch stderr. I changed it so now the same information is
placed in multiple lines and only failure is send to stderr.

Signed-off-by: Bart Smykla <bartek@smykla.com>

pkg/transparentproxy/iptables/builder/builder.go

@@ -94,8 +94,8 @@ func BuildIPTables(
 // runtimeOutput is the file (should be os.Stdout by default) where we can dump generated
 // rules for used to see and debug if something goes wrong, which can be overwritten
 // in tests to not obfuscate the other, more relevant logs
-func (r *restorer) saveIPTablesRestoreFile(f *os.File, content string) error {
-	fmt.Fprintf(r.cfg.RuntimeStdout, "# writing following contents to rules file: %s\n", f.Name())
+func (r *restorer) saveIPTablesRestoreFile(logPrefix string, f *os.File, content string) error {
+	fmt.Fprintf(r.cfg.RuntimeStdout, "%s writing following contents to rules file: %s\n", logPrefix, f.Name())
 	fmt.Fprint(r.cfg.RuntimeStdout, content)
 
 	writer := bufio.NewWriter(f)
@@ -164,36 +164,40 @@ func (r *restorer) restore(ctx context.Context) (string, error) {
 	maxRetries := pointer.Deref(r.cfg.Retry.MaxRetries)
 
 	for i := 0; i <= maxRetries; i++ {
-		fmt.Fprintf(r.cfg.RuntimeStderr, "\n# [%d/%d] ", i+1, maxRetries+1)
+		logPrefix := fmt.Sprintf("# [%d/%d]", i+1, maxRetries+1)
 
-		output, err := r.tryRestoreIPTables(ctx, r.executables, rulesFile)
+		output, err := r.tryRestoreIPTables(ctx, logPrefix, r.executables, rulesFile)
 		if err == nil {
 			return output, nil
 		}
 
 		if r.executables.fallback != nil {
-			fmt.Fprintf(r.cfg.RuntimeStderr, ", trying fallback: ")
+			fmt.Fprintf(r.cfg.RuntimeStdout, "%s trying fallback\n", logPrefix)
 
-			output, err := r.tryRestoreIPTables(ctx, r.executables.fallback, rulesFile)
+			output, err := r.tryRestoreIPTables(ctx, logPrefix, r.executables.fallback, rulesFile)
 			if err == nil {
 				return output, nil
 			}
 		}
 
 		if i < maxRetries {
-			fmt.Fprintf(r.cfg.RuntimeStderr, " will try again in %s", r.cfg.Retry.SleepBetweenReties)
+			fmt.Fprintf(
+				r.cfg.RuntimeStdout,
+				"%s will try again in %s\n",
+				logPrefix,
+				r.cfg.Retry.SleepBetweenReties,
+			)
 
 			time.Sleep(r.cfg.Retry.SleepBetweenReties)
 		}
 	}
 
-	fmt.Fprintln(r.cfg.RuntimeStderr)
-
 	return "", errors.Errorf("%s failed", r.executables.Restore.Path)
 }
 
 func (r *restorer) tryRestoreIPTables(
 	ctx context.Context,
+	logPrefix string,
 	executables *Executables,
 	rulesFile *os.File,
 ) (string, error) {
@@ -206,20 +210,31 @@ func (r *restorer) tryRestoreIPTables(
 		return "", fmt.Errorf("unable to build iptable rules: %s", err)
 	}
 
-	if err := r.saveIPTablesRestoreFile(rulesFile, rules); err != nil {
+	if err := r.saveIPTablesRestoreFile(logPrefix, rulesFile, rules); err != nil {
 		return "", fmt.Errorf("unable to save iptables restore file: %s", err)
 	}
 
-	params := buildRestoreParameters(r.cfg, rulesFile, executables.legacy)
+	params := buildRestoreParameters(r.cfg, rulesFile, executables.legacy())
 
-	fmt.Fprintf(r.cfg.RuntimeStderr, "%s %s", executables.Restore.Path, strings.Join(params, " "))
+	fmt.Fprintf(
+		r.cfg.RuntimeStdout,
+		"%s %s %s\n",
+		logPrefix,
+		executables.Restore.Path,
+		strings.Join(params, " "),
+	)
 
 	output, err := executables.Restore.exec(ctx, params...)
 	if err == nil {
 		return output.String(), nil
 	}
 
-	fmt.Fprintf(r.cfg.RuntimeStderr, " failed with error: '%s'", err)
+	fmt.Fprintf(
+		r.cfg.RuntimeStderr,
+		"%s failed with error: '%s'\n",
+		logPrefix,
+		strings.ReplaceAll(err.Error(), "\n", ""),
+	)
 
 	return "", err
 }
@@ -265,8 +280,7 @@ func RestoreIPTables(ctx context.Context, cfg config.Config) (string, error) {
 		output += ipv6Output
 	}
 
-	_, _ = cfg.RuntimeStdout.Write([]byte("\n# iptables set to diverge the traffic " +
-		"to Envoy.\n"))
+	fmt.Fprintln(cfg.RuntimeStdout, "# iptables set to divert the traffic to Envoy")
 
 	return output, nil
 }

pkg/transparentproxy/iptables/builder/builder_restore.go

@@ -92,7 +92,7 @@ type Executables struct {
 	Save                   Executable
 	Restore                Executable
 	fallback               *Executables
-	legacy                 bool
+	mode                   string
 	foundDockerOutputChain bool
 }
 
@@ -110,7 +110,7 @@ func newExecutables(ipv6 bool, mode string) *Executables {
 		Iptables: findExecutable(iptables),
 		Save:     findExecutable(iptablesSave),
 		Restore:  findExecutable(iptablesRestore),
-		legacy:   mode == "legacy",
+		mode:     mode,
 	}
 }
 
@@ -120,6 +120,10 @@ var necessaryMatchExtensions = []string{
 	"udp",
 }
 
+func (e *Executables) legacy() bool {
+	return e.mode == "legacy"
+}
+
 func (e *Executables) verify(ctx context.Context, cfg config.Config) (*Executables, error) {
 	var missing []string
 
@@ -132,7 +136,7 @@ func (e *Executables) verify(ctx context.Context, cfg config.Config) (*Executabl
 	}
 
 	if len(missing) > 0 {
-		return nil, errors.Errorf("couldn't find executables: [%s]", strings.Join(missing, ","))
+		return nil, errors.Errorf("couldn't find %s executables: [%s]", e.mode, strings.Join(missing, ", "))
 	}
 
 	// We always need to have access to the "nat" table