Improve shim debug logging

- Add log statements in service entry points.
- Propagate `-debug` flag from shim invokation to the service
- Load options when shim process is invoked to ensure runsc commands
  use the correct set of options, e.g. --debug --debug-logs=...
- Add debug options to the shim configuration directly, so it doesn't
  rely on containerd configuration (and restart) to enable shim debug.
- Save shim logs to dedicated file, so it's easier to read logs. They
  would be mixed with containerd logs and hard to distinguish
  otherwise.

PiperOrigin-RevId: 342179868

2 files changed, 39 insertions, 6 deletions

diff --git a/pkg/shim/runsc/runsc.go b/pkg/shim/runsc/runsc.go
index e7c9640ba..aedaf5ee5 100644
--- a/pkg/shim/runsc/runsc.go
+++ b/pkg/shim/runsc/runsc.go
@@ -13,6 +13,7 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+// Package runsc provides an API to interact with runsc command line.
 package runsc
 
 import (
@@ -33,12 +34,32 @@ import (
 	specs "github.com/opencontainers/runtime-spec/specs-go"
 )
 
-// Monitor is the default process monitor to be used by runsc.
-var Monitor runc.ProcessMonitor = runc.Monitor
-
 // DefaultCommand is the default command for Runsc.
 const DefaultCommand = "runsc"
 
+// Monitor is the default process monitor to be used by runsc.
+var Monitor runc.ProcessMonitor = &LogMonitor{Next: runc.Monitor}
+
+// LogMonitor implements the runc.ProcessMonitor interface, logging the command
+// that is getting executed, and then forwarding the call to another
+// implementation.
+type LogMonitor struct {
+	Next runc.ProcessMonitor
+}
+
+// Start implements runc.ProcessMonitor.
+func (l *LogMonitor) Start(cmd *exec.Cmd) (chan runc.Exit, error) {
+	log.L.Debugf("Executing: %s", cmd.Args)
+	return l.Next.Start(cmd)
+}
+
+// Wait implements runc.ProcessMonitor.
+func (l *LogMonitor) Wait(cmd *exec.Cmd, ch chan runc.Exit) (int, error) {
+	status, err := l.Next.Wait(cmd, ch)
+	log.L.Debugf("Command exit code: %d, err: %v", status, err)
+	return status, err
+}
+
 // Runsc is the client to the runsc cli.
 type Runsc struct {
 	Command      string
@@ -370,9 +391,10 @@ func (r *Runsc) Stats(context context.Context, id string) (*runc.Stats, error) {
 	}()
 	var e runc.Event
 	if err := json.NewDecoder(rd).Decode(&e); err != nil {
+		log.L.Debugf("Parsing events error: %v", err)
 		return nil, err
 	}
-	log.L.Debugf("Stats returned: %+v", e.Stats)
+	log.L.Debugf("Stats returned, type: %s, stats: %+v", e.Type, e.Stats)
 	if e.Type != "stats" {
 		return nil, fmt.Errorf(`unexpected event type %q, wanted "stats"`, e.Type)
 	}
diff --git a/pkg/shim/runsc/utils.go b/pkg/shim/runsc/utils.go
index c514b3bc7..55f17d29e 100644
--- a/pkg/shim/runsc/utils.go
+++ b/pkg/shim/runsc/utils.go
@@ -36,9 +36,20 @@ func putBuf(b *bytes.Buffer) {
 	bytesBufferPool.Put(b)
 }
 
-// FormatLogPath parses runsc config, and fill in %ID% in the log path.
-func FormatLogPath(id string, config map[string]string) {
+// FormatRunscLogPath parses runsc config, and fill in %ID% in the log path.
+func FormatRunscLogPath(id string, config map[string]string) {
 	if path, ok := config["debug-log"]; ok {
 		config["debug-log"] = strings.Replace(path, "%ID%", id, -1)
 	}
 }
+
+// FormatShimLogPath creates the file path to the log file. It replaces %ID%
+// in the path with the provided "id". It also uses a default log name if the
+// path end with '/'.
+func FormatShimLogPath(path string, id string) string {
+	if strings.HasSuffix(path, "/") {
+		// Default format: <path>/runsc-shim-<ID>.log
+		path += "runsc-shim-%ID%.log"
+	}
+	return strings.Replace(path, "%ID%", id, -1)
+}