Improve logging to kusto for better debugging

go.mod

@@ -4,7 +4,7 @@ go 1.22
 
 require (
 	github.com/Azure/azure-docker-extension v0.0.0-20160802215703-0dd2f199467d
-	github.com/Azure/azure-extension-platform v0.0.0-20240327184133-73b5b3b55955
+	github.com/Azure/azure-extension-platform v0.0.0-20240521173920-6b2acfda81e9
 	github.com/containerd/cgroups/v3 v3.0.2
 	github.com/opencontainers/runtime-spec v1.0.2
 	github.com/pkg/errors v0.9.1

go.sum

@@ -1,7 +1,7 @@
 github.com/Azure/azure-docker-extension v0.0.0-20160802215703-0dd2f199467d h1:IZq7wAvhHb/IObHOh8RHClV2zv4dHh5MrHdRWTTIwe0=
 github.com/Azure/azure-docker-extension v0.0.0-20160802215703-0dd2f199467d/go.mod h1:tVA4DYQYxotjw+EkJhfywtM99w7nAOatBvgNAkpsBvk=
-github.com/Azure/azure-extension-platform v0.0.0-20240327184133-73b5b3b55955 h1:klRZMtNE2mFdG8mO3+Ep7Armk1oewdw/7Z4nANDiGgk=
-github.com/Azure/azure-extension-platform v0.0.0-20240327184133-73b5b3b55955/go.mod h1:nEQQIC3RKmMnpdc+RakYHIdu556jdcHv67ML8PdsQeQ=
+github.com/Azure/azure-extension-platform v0.0.0-20240521173920-6b2acfda81e9 h1:/DP5C4Fx89JD/Te5ZDIG5hNNqUS0Jkaytqk+FP0owpM=
+github.com/Azure/azure-extension-platform v0.0.0-20240521173920-6b2acfda81e9/go.mod h1:nEQQIC3RKmMnpdc+RakYHIdu556jdcHv67ML8PdsQeQ=
 github.com/cilium/ebpf v0.9.1 h1:64sn2K3UKw8NbP/blsixRpF3nXuyhz/VjRlRzvlBRu4=
 github.com/cilium/ebpf v0.9.1/go.mod h1:+OhNOIXx/Fnu1IE8bJz2dzOA+VSfyTfdNUVdlQnxUFY=
 github.com/containerd/cgroups/v3 v3.0.2 h1:f5WFqIVSgo5IZmtTT3qVBo6TzI1ON6sycSBKkymb9L0=

internal/handlerenv/handlerenv.go

@@ -12,7 +12,7 @@ type HandlerEnvironment struct {
 }
 
 func (he *HandlerEnvironment) String() string {
-	env, _ := json.MarshalIndent(he, "", "    ")
+	env, _ := json.MarshalIndent(he, "", "\t")
 	return string(env)
 }
 

main/handlersettings.go

@@ -28,7 +28,7 @@ type handlerSettings struct {
 }
 
 func (s handlerSettings) String() string {
-	settings, _ := json.MarshalIndent(s, "", "    ")
+	settings, _ := json.MarshalIndent(s, "", "\t")
 	return string(settings)
 }
 
@@ -113,7 +113,7 @@ type vmWatchSettings struct {
 }
 
 func (v *vmWatchSettings) String() string {
-	setting, _ := json.MarshalIndent(v, "", "    ")
+	setting, _ := json.MarshalIndent(v, "", "\t")
 	return string(setting)
 }
 

main/main.go

@@ -36,6 +36,7 @@ func main() {
 
 	logger = log.With(logger, "time", log.DefaultTimestamp)
 	logger = log.With(logger, "version", VersionString())
+	logger = log.With(logger, "pid", os.Getpid())
 
 	// parse command line arguments
 	cmd := parseCmd(os.Args)
@@ -68,12 +69,13 @@ func main() {
 	eem = extensionevents.New(logging.NewNopLogger(), &hEnv.HandlerEnvironment)
 	sendTelemetry = telemetry.LogStdOutAndEventWithSender(telemetry.NewTelemetryEventSender(eem))
 	// check sub-command preconditions, if any, before executing
-	sendTelemetry(logger, telemetry.EventLevelInfo, telemetry.MainTask, fmt.Sprintf("Starting AppHealth Extension %s", GetExtensionVersion()))
+	sendTelemetry(logger, telemetry.EventLevelInfo, telemetry.MainTask, fmt.Sprintf("Starting AppHealth Extension %s seqNum=%d operation=%s", GetExtensionVersion(), seqNum, cmd.name))
 	sendTelemetry(logger, telemetry.EventLevelInfo, telemetry.MainTask, fmt.Sprintf("HandlerEnviroment = %s", hEnv))
 	if cmd.pre != nil {
 		logger.Log("event", "pre-check")
 		if err := cmd.pre(logger, seqNum); err != nil {
 			logger.Log("event", "pre-check failed", "error", err)
+			sendTelemetry(logger, telemetry.EventLevelError, telemetry.MainTask, fmt.Sprintf("pre-check failed with error %s", err))
 			os.Exit(cmd.failExitCode)
 		}
 	}
@@ -86,7 +88,7 @@ func main() {
 		os.Exit(cmd.failExitCode)
 	}
 	reportStatus(logger, hEnv, seqNum, StatusSuccess, cmd, msg)
-	sendTelemetry(logger, telemetry.EventLevelInfo, telemetry.MainTask, fmt.Sprintf("Finished execution of AppHealth Extension %s", GetExtensionVersion()))
+	sendTelemetry(logger, telemetry.EventLevelInfo, telemetry.MainTask, fmt.Sprintf("Finished execution of AppHealth Extension %s seqNum=%d operation=%s", GetExtensionVersion(), seqNum, cmd.name))
 }
 
 // parseCmd looks at os.Args and parses the subcommand. If it is invalid,

main/reportstatus.go

@@ -1,6 +1,8 @@
 package main
 
 import (
+	"fmt"
+
 	"github.com/Azure/applicationhealth-extension-linux/internal/handlerenv"
 	"github.com/Azure/applicationhealth-extension-linux/internal/telemetry"
 	"github.com/go-kit/log"
@@ -19,9 +21,11 @@ func reportStatus(lg log.Logger, hEnv *handlerenv.HandlerEnvironment, seqNum int
 	}
 	s := NewStatus(t, c.name, statusMsg(c, t, msg))
 	if err := s.Save(hEnv.StatusFolder, seqNum); err != nil {
-		lg.Log("event", "failed to save handler status", "error", err)
+		sendTelemetry(lg, telemetry.EventLevelError, telemetry.ReportStatusTask, fmt.Sprintf("failed to save handler status: %s", s), "error", err.Error())
 		return errors.Wrap(err, "failed to save handler status")
 	}
+	sendTelemetry(lg, telemetry.EventLevelInfo, telemetry.ReportStatusTask, fmt.Sprintf("saved handler status: %s", s))
+
 	return nil
 }
 
@@ -31,7 +35,7 @@ func reportStatusWithSubstatuses(lg log.Logger, hEnv *handlerenv.HandlerEnvironm
 		s.AddSubstatusItem(substatus)
 	}
 	if err := s.Save(hEnv.StatusFolder, seqNum); err != nil {
-		sendTelemetry(lg, telemetry.EventLevelInfo, telemetry.ReportStatusTask, "failed to save handler status", "error", err.Error())
+		sendTelemetry(lg, telemetry.EventLevelError, telemetry.ReportStatusTask, fmt.Sprintf("failed to save handler status: %s", s), "error", err.Error())
 		return errors.Wrap(err, "failed to save handler status")
 	}
 	return nil

main/reportstatus_test.go

@@ -9,9 +9,17 @@ import (
 	"github.com/go-kit/log"
 
 	"github.com/Azure/applicationhealth-extension-linux/internal/handlerenv"
+	"github.com/Azure/applicationhealth-extension-linux/internal/telemetry"
+	"github.com/Azure/applicationhealth-extension-linux/pkg/logging"
+	"github.com/Azure/azure-extension-platform/pkg/extensionevents"
 	"github.com/stretchr/testify/require"
 )
 
+func initTelemetry(he *handlerenv.HandlerEnvironment) {
+	eem = extensionevents.New(logging.NewNopLogger(), &he.HandlerEnvironment)
+	sendTelemetry = telemetry.LogStdOutAndEventWithSender(telemetry.NewTelemetryEventSender(eem))
+}
+
 func Test_statusMsg(t *testing.T) {
 	require.Equal(t, "Enable succeeded", statusMsg(cmdEnable, StatusSuccess, ""))
 	require.Equal(t, "Enable succeeded: msg", statusMsg(cmdEnable, StatusSuccess, "msg"))
@@ -27,6 +35,8 @@ func Test_reportStatus_fails(t *testing.T) {
 	fakeEnv := &handlerenv.HandlerEnvironment{}
 	fakeEnv.StatusFolder = "/non-existing/dir/"
 
+	initTelemetry(fakeEnv)
+
 	err := reportStatus(log.NewNopLogger(), fakeEnv, 1, StatusSuccess, cmdEnable, "")
 	require.NotNil(t, err)
 	require.Contains(t, err.Error(), "failed to save handler status")
@@ -39,6 +49,7 @@ func Test_reportStatus_fileExists(t *testing.T) {
 
 	fakeEnv := &handlerenv.HandlerEnvironment{}
 	fakeEnv.StatusFolder = tmpDir
+	initTelemetry(fakeEnv)
 
 	require.Nil(t, reportStatus(log.NewNopLogger(), fakeEnv, 1, StatusError, cmdEnable, "FOO ERROR"))
 
@@ -56,6 +67,8 @@ func Test_reportStatus_checksIfShouldBeReported(t *testing.T) {
 
 		fakeEnv := &handlerenv.HandlerEnvironment{}
 		fakeEnv.StatusFolder = tmpDir
+		initTelemetry(fakeEnv)
+
 		require.Nil(t, reportStatus(log.NewNopLogger(), fakeEnv, 2, StatusSuccess, c, ""))
 
 		fp := filepath.Join(tmpDir, "2.status")

main/status.go

@@ -124,3 +124,8 @@ func (r StatusReport) Save(statusFolder string, seqNum int) error {
 	}
 	return nil
 }
+
+func (r StatusReport) String() string {
+	report, _ := json.MarshalIndent(r, "", "\t")
+	return string(report)
+}

vendor/modules.txt

@@ -1,7 +1,7 @@
 # github.com/Azure/azure-docker-extension v0.0.0-20160802215703-0dd2f199467d
 ## explicit
 github.com/Azure/azure-docker-extension/pkg/vmextension
-# github.com/Azure/azure-extension-platform v0.0.0-20240327184133-73b5b3b55955
+# github.com/Azure/azure-extension-platform v0.0.0-20240521173920-6b2acfda81e9
 ## explicit; go 1.21
 github.com/Azure/azure-extension-platform/pkg/extensionerrors
 github.com/Azure/azure-extension-platform/pkg/extensionevents