logger: making log level configurable through meshconfig

New `osmLogLevel` option has been added under observability meshconfig
spec (seems the most related and relevant to the available categories)
to allow changing the log level of OSM at runtime.

The initial log level flag has been kept at it still mandates boot log
level up to the point configurator and the log level handler are both
up, which then meshconfig value takes over.

The handler can't be easilly moved to the `logger` package as it
introduces a hard dependency cycle between logger<->configurator, hence
the handler has been left on osm-controller main.

Adds a unit test, and see below a working example on a running deployment.

Fixes openservicemesh#3646

Signed-off-by: Eduard Serra <[email protected]>

charts/osm/crds/meshconfig.yaml

@@ -155,6 +155,10 @@ spec:
                   description: Configuration for observing the service mesh, including metrics, logs, tracing etc,.
                   type: object
                   properties:
+                    osmLogLevel:
+                      description: Allows setting OSM's log level at runtime
+                      type: string
+                      default: "info"
                     enableDebugServer:
                       description: Enables a debug endpoint on the osm-controller pod to list information regarding the mesh such as proxy connections, certificates, and SMI policies.
                       type: boolean

cmd/osm-controller/osm-controller.go

@@ -24,6 +24,7 @@ import (
 	_ "k8s.io/client-go/plugin/pkg/client/auth/gcp"
 	"k8s.io/client-go/tools/clientcmd"
 
+	"github.com/openservicemesh/osm/pkg/announcements"
 	"github.com/openservicemesh/osm/pkg/catalog"
 	"github.com/openservicemesh/osm/pkg/certificate"
 	"github.com/openservicemesh/osm/pkg/certificate/providers"
@@ -79,7 +80,7 @@ var (
 )
 
 func init() {
-	flags.StringVarP(&verbosity, "verbosity", "v", "info", "Set log verbosity level")
+	flags.StringVarP(&verbosity, "verbosity", "v", constants.DefaultOSMLogLevel, "Set boot log verbosity level")
 	flags.StringVar(&meshName, "mesh-name", "", "OSM mesh name")
 	flags.StringVar(&kubeConfigFile, "kubeconfig", "", "Path to Kubernetes config file")
 	flags.StringVar(&osmNamespace, "osm-namespace", "", "OSM controller's namespace")
@@ -157,6 +158,9 @@ func main() {
 	}
 	log.Info().Msgf("Initial MeshConfig %s: %s", osmMeshConfigName, meshConfig)
 
+	// Start Global log level handler, reads from configurator (meshconfig)
+	StartGlobalLogLevelHandler(cfg, stop)
+
 	kubernetesClient, err := k8s.NewKubernetesController(kubeClient, meshName, stop)
 	if err != nil {
 		events.GenericEventRecorder().FatalEvent(err, events.InitializationError, "Error creating Kubernetes Controller")
@@ -333,3 +337,44 @@ func getOSMControllerPod(kubeClient kubernetes.Interface) (*corev1.Pod, error) {
 
 	return pod, nil
 }
+
+// StartGlobalLogLevelHandler registers a listener to meshconfig events and log level changes,
+// and applies new log level at global scope
+func StartGlobalLogLevelHandler(cfg configurator.Configurator, stop <-chan struct{}) {
+	meshConfigChannel := events.GetPubSubInstance().Subscribe(
+		announcements.MeshConfigAdded,
+		announcements.MeshConfigDeleted,
+		announcements.MeshConfigUpdated)
+
+	// Run config listener
+	// Bootstrap after subscribing
+	currentLogLevel := constants.DefaultOSMLogLevel
+	logLevel := cfg.GetOSMLogLevel()
+	log.Info().Msgf("Setting initial log level from meshconfig: %s", logLevel)
+	err := logger.SetLogLevel(logLevel)
+	if err != nil {
+		log.Error().Msgf("Failed to set initial log level from meshconfig: %v", err)
+	} else {
+		currentLogLevel = logLevel
+	}
+
+	go func() {
+		for {
+			select {
+			case <-meshConfigChannel:
+				logLevel := cfg.GetOSMLogLevel()
+				if logLevel != currentLogLevel {
+					err := logger.SetLogLevel(logLevel)
+					if err != nil {
+						log.Error().Msgf("Failed to set log level from meshconfig: %v", err)
+					} else {
+						log.Info().Msgf("Global log level changed to: %s", logLevel)
+						currentLogLevel = logLevel
+					}
+				}
+			case <-stop:
+				return
+			}
+		}
+	}()
+}

cmd/osm-controller/osm-controller_test.go

@@ -2,8 +2,15 @@ package main
 
 import (
 	"testing"
+	"time"
 
+	"github.com/golang/mock/gomock"
+	"github.com/rs/zerolog"
 	tassert "github.com/stretchr/testify/assert"
+
+	"github.com/openservicemesh/osm/pkg/announcements"
+	"github.com/openservicemesh/osm/pkg/configurator"
+	"github.com/openservicemesh/osm/pkg/kubernetes/events"
 )
 
 func TestJoinURL(t *testing.T) {
@@ -25,3 +32,35 @@ func TestJoinURL(t *testing.T) {
 		assert.Equal(result, ju.expectedOutput)
 	}
 }
+
+func TestGlobalLogLevelHandler(t *testing.T) {
+	assert := tassert.New(t)
+	mockCtrl := gomock.NewController(t)
+	mockConfigurator := configurator.NewMockConfigurator(mockCtrl)
+
+	stop := make(chan struct{})
+	defer close(stop)
+
+	mockConfigurator.EXPECT().GetOSMLogLevel().Return("trace").Times(1)
+	StartGlobalLogLevelHandler(mockConfigurator, stop)
+
+	// Set log level through a meshconfig event
+	mockConfigurator.EXPECT().GetOSMLogLevel().Return("warn").Times(1)
+	events.GetPubSubInstance().Publish(events.PubSubMessage{
+		AnnouncementType: announcements.MeshConfigUpdated,
+	})
+
+	assert.Eventually(func() bool {
+		return zerolog.GlobalLevel() == zerolog.WarnLevel
+	}, 2*time.Second, 25*time.Millisecond, "Global log level did not change in specified time")
+
+	// Reset back
+	mockConfigurator.EXPECT().GetOSMLogLevel().Return("trace").Times(1)
+	events.GetPubSubInstance().Publish(events.PubSubMessage{
+		AnnouncementType: announcements.MeshConfigUpdated,
+	})
+
+	assert.Eventually(func() bool {
+		return zerolog.GlobalLevel() == zerolog.TraceLevel
+	}, 2*time.Second, 25*time.Millisecond, "Global log level did not reset to trace")
+}

pkg/apis/config/v1alpha1/mesh_config.go

@@ -91,6 +91,9 @@ type TrafficSpec struct {
 
 // ObservabilitySpec is the type to represent OSM's observability configurations.
 type ObservabilitySpec struct {
+	// OSMLogLevel defines the log level for OSM control plane logs
+	OSMLogLevel string `json:"osmLogLevel,omitempty"`
+
 	// EnableDebugServer defines if the debug endpoint on the OSM controller pod is enabled.
 	EnableDebugServer bool `json:"enableDebugServer,omitempty"`
 

pkg/configurator/client_test.go

@@ -166,6 +166,13 @@ func TestMeshConfigEventTriggers(t *testing.T) {
 			},
 			expectProxyBroadcast: true,
 		},
+		{
+			caseName: "osmLogLevel",
+			updateMeshConfigSpec: func(spec *v1alpha1.MeshConfigSpec) {
+				spec.Observability.OSMLogLevel = "warn"
+			},
+			expectProxyBroadcast: false,
+		},
 	}
 
 	for _, tc := range tests {

pkg/configurator/methods.go

@@ -203,3 +203,8 @@ func (c *Client) GetInboundExternalAuthConfig() auth.ExtAuthConfig {
 func (c *Client) GetFeatureFlags() v1alpha1.FeatureFlags {
 	return c.getMeshConfig().Spec.FeatureFlags
 }
+
+// GetOSMLogLevel returns the configured OSM log level
+func (c *Client) GetOSMLogLevel() string {
+	return c.getMeshConfig().Spec.Observability.OSMLogLevel
+}

pkg/configurator/methods_test.go

@@ -15,6 +15,7 @@ import (
 	testclient "github.com/openservicemesh/osm/pkg/gen/client/config/clientset/versioned/fake"
 
 	"github.com/openservicemesh/osm/pkg/announcements"
+	"github.com/openservicemesh/osm/pkg/constants"
 	"github.com/openservicemesh/osm/pkg/kubernetes/events"
 )
 
@@ -62,6 +63,7 @@ func TestCreateUpdateConfig(t *testing.T) {
 					UseHTTPSIngress:                   true,
 				},
 				Observability: v1alpha1.ObservabilitySpec{
+					OSMLogLevel:       constants.DefaultOSMLogLevel,
 					EnableDebugServer: true,
 					Tracing: v1alpha1.TracingSpec{
 						Enable: true,
@@ -87,6 +89,7 @@ func TestCreateUpdateConfig(t *testing.T) {
 						UseHTTPSIngress:                   true,
 					},
 					Observability: v1alpha1.ObservabilitySpec{
+						OSMLogLevel:       constants.DefaultOSMLogLevel,
 						EnableDebugServer: true,
 						Tracing: v1alpha1.TracingSpec{
 							Enable: true,
@@ -479,6 +482,25 @@ func TestCreateUpdateConfig(t *testing.T) {
 				assert.Equal(true, cfg.GetFeatureFlags().EnableAsyncProxyServiceMapping)
 			},
 		},
+		{
+			name: "OsmLogLevel",
+			initialMeshConfigData: &v1alpha1.MeshConfigSpec{
+				Observability: v1alpha1.ObservabilitySpec{
+					OSMLogLevel: constants.DefaultOSMLogLevel,
+				},
+			},
+			checkCreate: func(assert *tassert.Assertions, cfg Configurator) {
+				assert.Equal(constants.DefaultOSMLogLevel, cfg.GetOSMLogLevel())
+			},
+			updatedMeshConfigData: &v1alpha1.MeshConfigSpec{
+				Observability: v1alpha1.ObservabilitySpec{
+					OSMLogLevel: "warn",
+				},
+			},
+			checkUpdate: func(assert *tassert.Assertions, cfg Configurator) {
+				assert.Equal("warn", cfg.GetOSMLogLevel())
+			},
+		},
 	}
 
 	for _, test := range tests {

pkg/configurator/types.go

@@ -61,6 +61,9 @@ type Configurator interface {
 	// GetMaxDataPlaneConnections returns the max data plane connections allowed, 0 if disabled
 	GetMaxDataPlaneConnections() int
 
+	// GetOsmLogLevel returns the configured OSM log level
+	GetOSMLogLevel() string
+
 	// GetEnvoyLogLevel returns the envoy log level
 	GetEnvoyLogLevel() string
 

pkg/constants/constants.go

@@ -55,6 +55,9 @@ const (
 	// DefaultEnvoyLogLevel is the default envoy log level if not defined in the osm MeshConfig
 	DefaultEnvoyLogLevel = "error"
 
+	// DefaultOSMLogLevel is the default OSM log level if none is specified
+	DefaultOSMLogLevel = "info"
+
 	// DefaultEnvoyImage is the default envoy proxy sidecar image if not defined in the osm MeshConfig
 	DefaultEnvoyImage = "envoyproxy/envoy-alpine:v1.18.3"