Merge pull request #743 from doringeman/fix-logs

fix(cli): resolve infinite loop and output bugs in log merging

Author: doringeman

cmd/cli/commands/logs.go

@@ -78,25 +78,29 @@ func newLogsCmd() *cobra.Command {
 			}
 
 			if noEngines {
-				err = printMergedLog(serviceLogPath, "")
+				err = printMergedLog(cmd.OutOrStdout(), serviceLogPath, "")
 				if err != nil {
 					return err
 				}
 			} else {
-				err = printMergedLog(serviceLogPath, runtimeLogPath)
+				err = printMergedLog(cmd.OutOrStdout(), serviceLogPath, runtimeLogPath)
 				if err != nil {
 					return err
 				}
 			}
 
+			if !follow {
+				return nil
+			}
+
 			ctx, cancel := signal.NotifyContext(context.Background(), os.Interrupt, os.Kill)
 			defer cancel()
 
 			g, ctx := errgroup.WithContext(ctx)
 
 			g.Go(func() error {
 				t, err := tail.TailFile(
-					serviceLogPath, tail.Config{Location: &tail.SeekInfo{Offset: 0, Whence: io.SeekEnd}, Follow: follow, ReOpen: follow},
+					serviceLogPath, tail.Config{Location: &tail.SeekInfo{Offset: 0, Whence: io.SeekEnd}, Follow: true, ReOpen: true},
 				)
 				if err != nil {
 					return err
@@ -107,19 +111,17 @@ func newLogsCmd() *cobra.Command {
 						if !ok {
 							return nil
 						}
-						fmt.Println(line.Text)
+						cmd.Println(line.Text)
 					case <-ctx.Done():
 						return t.Stop()
 					}
 				}
 			})
 
-			if follow && !noEngines {
-				// Show inference engines logs if `follow` is enabled
-				// and the engines logs have not been skipped by setting `--no-engines`.
+			if !noEngines {
 				g.Go(func() error {
 					t, err := tail.TailFile(
-						runtimeLogPath, tail.Config{Location: &tail.SeekInfo{Offset: 0, Whence: io.SeekEnd}, Follow: follow, ReOpen: follow},
+						runtimeLogPath, tail.Config{Location: &tail.SeekInfo{Offset: 0, Whence: io.SeekEnd}, Follow: true, ReOpen: true},
 					)
 					if err != nil {
 						return err
@@ -131,7 +133,7 @@ func newLogsCmd() *cobra.Command {
 							if !ok {
 								return nil
 							}
-							fmt.Println(line.Text)
+							cmd.Println(line.Text)
 						case <-ctx.Done():
 							return t.Stop()
 						}
@@ -152,7 +154,7 @@ var timestampRe = regexp.MustCompile(`\[(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d
 
 const timeFmt = "2006-01-02T15:04:05.000000000Z"
 
-func printTillFirstTimestamp(logScanner *bufio.Scanner) (time.Time, string) {
+func advanceToNextTimestamp(w io.Writer, logScanner *bufio.Scanner) (time.Time, string) {
 	if logScanner == nil {
 		return time.Time{}, ""
 	}
@@ -163,18 +165,18 @@ func printTillFirstTimestamp(logScanner *bufio.Scanner) (time.Time, string) {
 		if len(match) == 2 {
 			timestamp, err := time.Parse(timeFmt, match[1])
 			if err != nil {
-				println(text)
+				fmt.Fprintln(w, text)
 				continue
 			}
 			return timestamp, text
 		} else {
-			println(text)
+			fmt.Fprintln(w, text)
 		}
 	}
 	return time.Time{}, ""
 }
 
-func printMergedLog(logPath1, logPath2 string) error {
+func printMergedLog(w io.Writer, logPath1, logPath2 string) error {
 	var logScanner1 *bufio.Scanner
 	if logPath1 != "" {
 		logFile1, err := os.Open(logPath1)
@@ -195,31 +197,32 @@ func printMergedLog(logPath1, logPath2 string) error {
 
 	var timestamp1 time.Time
 	var timestamp2 time.Time
-	var log1Line string
-	var log2Name string
+	var line1 string
+	var line2 string
 
-	timestamp1, log1Line = printTillFirstTimestamp(logScanner1)
-	timestamp2, log2Name = printTillFirstTimestamp(logScanner2)
+	timestamp1, line1 = advanceToNextTimestamp(w, logScanner1)
+	timestamp2, line2 = advanceToNextTimestamp(w, logScanner2)
 
-	for log1Line != "" && log2Name != "" {
-		for log1Line != "" && timestamp1.Before(timestamp2) {
-			println(log1Line)
-			timestamp1, log1Line = printTillFirstTimestamp(logScanner1)
-		}
-		for log2Name != "" && timestamp2.Before(timestamp1) {
-			println(log2Name)
-			timestamp2, log2Name = printTillFirstTimestamp(logScanner2)
+	for line1 != "" && line2 != "" {
+		if !timestamp2.Before(timestamp1) {
+			fmt.Fprintln(w, line1)
+			timestamp1, line1 = advanceToNextTimestamp(w, logScanner1)
+		} else {
+			fmt.Fprintln(w, line2)
+			timestamp2, line2 = advanceToNextTimestamp(w, logScanner2)
 		}
 	}
 
-	if log1Line != "" {
+	if line1 != "" {
+		fmt.Fprintln(w, line1)
 		for logScanner1.Scan() {
-			println(logScanner1.Text())
+			fmt.Fprintln(w, logScanner1.Text())
 		}
 	}
-	if log2Name != "" {
+	if line2 != "" {
+		fmt.Fprintln(w, line2)
 		for logScanner2.Scan() {
-			println(logScanner2.Text())
+			fmt.Fprintln(w, logScanner2.Text())
 		}
 	}
 

cmd/cli/commands/logs_test.go

@@ -0,0 +1,74 @@
+package commands
+
+import (
+	"bytes"
+	"io"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+	"time"
+)
+
+func TestMergedLogEqualTimestamps(t *testing.T) {
+	f1 := filepath.Join(t.TempDir(), "a.log")
+	if err := os.WriteFile(f1, []byte("[2026-03-09T12:00:00.000000000Z] line a\n"), 0644); err != nil {
+		t.Fatal(err)
+	}
+	f2 := filepath.Join(t.TempDir(), "b.log")
+	if err := os.WriteFile(f2, []byte("[2026-03-09T12:00:00.000000000Z] line b\n"), 0644); err != nil {
+		t.Fatal(err)
+	}
+
+	done := make(chan error, 1)
+	go func() { done <- printMergedLog(io.Discard, f1, f2) }()
+
+	select {
+	case <-done:
+		// ok
+	case <-time.After(3 * time.Second):
+		t.Fatal("printMergedLog hung — equal timestamp deadlock")
+	}
+}
+
+func TestMergedLogInterleavedTimestamps(t *testing.T) {
+	f1 := filepath.Join(t.TempDir(), "a.log")
+	if err := os.WriteFile(f1, []byte(strings.Join([]string{
+		"[2026-03-09T12:00:00.000000000Z] a1",
+		"[2026-03-09T12:00:02.000000000Z] a2",
+		"[2026-03-09T12:00:04.000000000Z] a3",
+	}, "\n")+"\n"), 0644); err != nil {
+		t.Fatal(err)
+	}
+
+	f2 := filepath.Join(t.TempDir(), "b.log")
+	if err := os.WriteFile(f2, []byte(strings.Join([]string{
+		"[2026-03-09T12:00:00.000000000Z] b1",
+		"[2026-03-09T12:00:01.000000000Z] b2",
+		"[2026-03-09T12:00:03.000000000Z] b3",
+		"[2026-03-09T12:00:05.000000000Z] b4",
+	}, "\n")+"\n"), 0644); err != nil {
+		t.Fatal(err)
+	}
+
+	var buf bytes.Buffer
+	err := printMergedLog(&buf, f1, f2)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	got := strings.TrimSpace(buf.String())
+	want := strings.Join([]string{
+		"[2026-03-09T12:00:00.000000000Z] a1",
+		"[2026-03-09T12:00:00.000000000Z] b1",
+		"[2026-03-09T12:00:01.000000000Z] b2",
+		"[2026-03-09T12:00:02.000000000Z] a2",
+		"[2026-03-09T12:00:03.000000000Z] b3",
+		"[2026-03-09T12:00:04.000000000Z] a3",
+		"[2026-03-09T12:00:05.000000000Z] b4",
+	}, "\n")
+
+	if got != want {
+		t.Errorf("wrong merge order:\ngot:\n%s\nwant:\n%s", got, want)
+	}
+}