[test]logging and tracing to stdout

test/functional/main_test.go

@@ -20,9 +20,11 @@ import (
 
 	"github.com/containerd/containerd/namespaces"
 	"github.com/sirupsen/logrus"
+	"go.opencensus.io/trace"
 
 	"github.com/Microsoft/hcsshim/internal/cow"
 	"github.com/Microsoft/hcsshim/internal/hcsoci"
+	"github.com/Microsoft/hcsshim/internal/oc"
 	"github.com/Microsoft/hcsshim/internal/resources"
 	"github.com/Microsoft/hcsshim/internal/uvm"
 	"github.com/Microsoft/hcsshim/internal/winapi"
@@ -84,10 +86,8 @@ var allFeatures = []string{
 var (
 	flagPauseAfterCreateContainerFailure time.Duration
 
-	flagFeatures = testflag.NewFeatureFlag(allFeatures)
-	flagDebug    = flag.Bool("debug",
-		os.Getenv("HCSSHIM_FUNCTIONAL_TESTS_DEBUG") != "",
-		"set logging level to debug [%HCSSHIM_FUNCTIONAL_TESTS_DEBUG%]")
+	flagLogLevel            = testflag.NewLogrusLevel("log-level", defaultLogLevel(), "logrus logging `level`")
+	flagFeatures            = testflag.NewFeatureFlag(allFeatures)
 	flagContainerdNamespace = flag.String("ctr-namespace", hcsOwner,
 		"containerd `namespace` to use when creating OCI specs")
 	flagLCOWLayerPaths = testflag.NewStringSlice("lcow-layer-paths",
@@ -124,13 +124,16 @@ func init() {
 func TestMain(m *testing.M) {
 	flag.Parse()
 
-	lvl := logrus.WarnLevel
-	if *flagDebug {
-		lvl = logrus.DebugLevel
-	}
-	logrus.SetLevel(lvl)
+	trace.ApplyConfig(trace.Config{DefaultSampler: oc.DefaultSampler})
+	trace.RegisterExporter(&oc.LogrusExporter{})
+
+	// default is stderr, but test2json does not consume stderr, so logs would be out of sync
+	// and powershell considers output on stderr as an error when execing
+	logrus.SetOutput(os.Stdout)
 	logrus.SetFormatter(&logrus.TextFormatter{FullTimestamp: true})
-	logrus.Infof("using features %q", flagFeatures.S.Strings())
+	logrus.SetLevel(flagLogLevel.Level)
+
+	logrus.Debugf("using features %q", flagFeatures.S.Strings())
 
 	images := []*layers.LazyImageLayers{alpineImagePaths, nanoserverImagePaths, servercoreImagePaths}
 	for _, l := range images {
@@ -233,3 +236,10 @@ func windowsServercoreImageLayers(ctx context.Context, tb testing.TB) []string {
 func namespacedContext() context.Context {
 	return namespaces.WithNamespace(context.Background(), *flagContainerdNamespace)
 }
+
+func defaultLogLevel() string {
+	if os.Getenv("HCSSHIM_FUNCTIONAL_TESTS_DEBUG") != "" {
+		return logrus.DebugLevel.String()
+	}
+	return logrus.WarnLevel.String()
+}

test/functional/uvm_update_test.go

@@ -10,12 +10,17 @@ import (
 	"github.com/opencontainers/runtime-spec/specs-go"
 
 	"github.com/Microsoft/hcsshim/internal/protocol/guestrequest"
+	"github.com/Microsoft/hcsshim/osversion"
 	"github.com/Microsoft/hcsshim/pkg/ctrdtaskapi"
 
+	"github.com/Microsoft/hcsshim/test/internal/require"
 	"github.com/Microsoft/hcsshim/test/internal/uvm"
 )
 
 func Test_LCOW_Update_Resources(t *testing.T) {
+	requireFeatures(t, featureLCOW)
+	require.Build(t, osversion.RS5)
+
 	for _, config := range []struct {
 		name     string
 		resource interface{}

test/gcs/main_test.go

@@ -8,19 +8,19 @@ import (
 	"fmt"
 	"log"
 	"os"
-	"strconv"
 	"testing"
 
-	"github.com/Microsoft/hcsshim/internal/protocol/guestresource"
-
 	"github.com/containerd/cgroups"
 	"github.com/sirupsen/logrus"
+	"go.opencensus.io/trace"
 
 	"github.com/Microsoft/hcsshim/internal/guest/runtime"
 	"github.com/Microsoft/hcsshim/internal/guest/runtime/hcsv2"
 	"github.com/Microsoft/hcsshim/internal/guest/runtime/runc"
 	"github.com/Microsoft/hcsshim/internal/guest/transport"
 	"github.com/Microsoft/hcsshim/internal/guestpath"
+	"github.com/Microsoft/hcsshim/internal/oc"
+	"github.com/Microsoft/hcsshim/internal/protocol/guestresource"
 	"github.com/Microsoft/hcsshim/pkg/securitypolicy"
 
 	testflag "github.com/Microsoft/hcsshim/test/internal/flag"
@@ -38,6 +38,7 @@ var allFeatures = []string{
 }
 
 var (
+	flagLogLevel      = testflag.NewLogrusLevel("log-level", "warning", "logrus logging `level`")
 	flagFeatures      = testflag.NewFeatureFlag(allFeatures)
 	flagJoinGCSCgroup = flag.Bool(
 		"join-gcs-cgroup",
@@ -78,15 +79,16 @@ func TestMain(m *testing.M) {
 func setup() (err error) {
 	_ = os.MkdirAll(guestpath.LCOWRootPrefixInUVM, 0755)
 
-	if vf := flag.Lookup("test.v"); vf != nil {
-		if vf.Value.String() == strconv.FormatBool(true) {
-			logrus.SetLevel(logrus.DebugLevel)
-		} else {
-			logrus.SetLevel(logrus.ErrorLevel)
-		}
-	}
+	trace.ApplyConfig(trace.Config{DefaultSampler: oc.DefaultSampler})
+	trace.RegisterExporter(&oc.LogrusExporter{})
+
+	logrus.SetLevel(flagLogLevel.Level)
+	// test2json does not consume stderr
+	logrus.SetOutput(os.Stdout)
+	logrus.SetFormatter(&logrus.TextFormatter{FullTimestamp: true})
+	logrus.Infof("using features %q", flagFeatures.S.Strings())
 
-	// should already start gcs cgroup
+	// should already start in gcs cgroup
 	if !*flagJoinGCSCgroup {
 		gcsControl, err := cgroups.Load(cgroups.V1, cgroups.StaticPath("/"))
 		if err != nil {

test/go.mod

@@ -20,6 +20,7 @@ require (
 	github.com/pkg/errors v0.9.1
 	github.com/sirupsen/logrus v1.9.0
 	github.com/stretchr/testify v1.8.0
+	go.opencensus.io v0.23.0
 	golang.org/x/sync v0.0.0-20220722155255-886fb9371eb4
 	golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f
 	google.golang.org/grpc v1.47.0
@@ -77,7 +78,6 @@ require (
 	github.com/xeipuuv/gojsonreference v0.0.0-20180127040603-bd5ef7bd5415 // indirect
 	github.com/xeipuuv/gojsonschema v1.2.0 // indirect
 	github.com/yashtewari/glob-intersection v0.1.0 // indirect
-	go.opencensus.io v0.23.0 // indirect
 	golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4 // indirect
 	golang.org/x/net v0.0.0-20220722155237-a158d28d115b // indirect
 	golang.org/x/text v0.3.7 // indirect

test/internal/flag/flag.go

@@ -6,6 +6,8 @@ package flag
 import (
 	"flag"
 	"strings"
+
+	"github.com/sirupsen/logrus"
 )
 
 const FeatureFlagName = "feature"
@@ -74,3 +76,40 @@ func (ss StringSet) String() string {
 func Standardize(s string) string {
 	return strings.ToLower(strings.TrimSpace(s))
 }
+
+// LogrusLevel is a flag that accepts logrus logging levels, as strings.
+type LogrusLevel struct {
+	Level logrus.Level
+}
+
+var _ flag.Value = &LogrusLevel{}
+
+func NewLogrusLevel(name, value, usage string) *LogrusLevel {
+	l := &LogrusLevel{}
+	if lvl, err := logrus.ParseLevel(value); err == nil {
+		l.Level = lvl
+	} else {
+		l.Level = logrus.StandardLogger().Level
+	}
+	flag.Var(l, name, usage)
+	return l
+}
+
+func (l *LogrusLevel) String() string {
+	// may be called ona nil receiver
+	// return default level
+	if l == nil {
+		return logrus.StandardLogger().Level.String()
+	}
+
+	return l.Level.String()
+}
+
+func (l *LogrusLevel) Set(s string) error {
+	lvl, err := logrus.ParseLevel(s)
+	if err != nil {
+		return err
+	}
+	l.Level = lvl
+	return nil
+}