Set grpc logger to collector

CHANGELOG.md

@@ -14,6 +14,7 @@
 - Remove `pdata.AttributeMap.InitFromMap` (#4429)
 - Updated configgrpc `ToDialOptions` to support passing providers to instrumentation library (#4451)
 - Make state information propagation non-blocking on the collector (#4460)
+- Added support to expose gRPC framework's logs as part of collector logs (#4501)
 
 ## 💡 Enhancements 💡
 

examples/local/otel-config.bak

@@ -0,0 +1,44 @@
+extensions:
+  memory_ballast:
+    size_mib: 512
+  zpages:
+    endpoint: 0.0.0.0:55679
+
+receivers:
+  otlp:
+    protocols:
+      grpc:
+      http:
+
+processors:
+  batch:
+  memory_limiter:
+    # 75% of maximum memory up to 4G
+    limit_mib: 1536
+    # 25% of limit up to 2G
+    spike_limit_mib: 512
+    check_interval: 5s
+
+exporters:
+  logging:
+    logLevel: info
+  otlp:
+    endpoint: non_exist
+
+service:
+  telemetry:
+    logs:
+      level: "DEBUG"
+      development: false
+      encoding: "json"
+  pipelines:
+    traces:
+      receivers: [otlp]
+      processors: [memory_limiter, batch]
+      exporters: [logging, otlp]
+    metrics:
+      receivers: [otlp]
+      processors: [memory_limiter, batch]
+      exporters: [logging]
+
+  extensions: [memory_ballast, zpages]

go.mod

@@ -8,6 +8,7 @@ require (
 	github.com/gogo/protobuf v1.3.2
 	github.com/google/uuid v1.3.0
 	github.com/gorilla/mux v1.8.0
+	github.com/grpc-ecosystem/go-grpc-middleware v1.3.0
 	github.com/knadh/koanf v1.3.3
 	github.com/magiconair/properties v1.8.5
 	github.com/mitchellh/mapstructure v1.4.2

go.sum

@@ -214,6 +214,8 @@ github.com/googleapis/gax-go/v2 v2.0.5/go.mod h1:DWXyrwAJ9X0FpwwEdw+IPEYBICEFu5m
 github.com/gopherjs/gopherjs v0.0.0-20181017120253-0766667cb4d1/go.mod h1:wJfORRmW1u3UXTncJ5qlYoELFm8eSnnEO6hX4iZ3EWY=
 github.com/gorilla/mux v1.8.0 h1:i40aqfkR1h2SlN9hojwV5ZA91wcXFOvkdNIeFDP5koI=
 github.com/gorilla/mux v1.8.0/go.mod h1:DVbg23sWSpFRCP0SfiEN6jmj59UnW/n46BH5rLB71So=
+github.com/grpc-ecosystem/go-grpc-middleware v1.3.0 h1:+9834+KizmvFV7pXQGSXQTsaWhq2GjuNUt0aUU0YBYw=
+github.com/grpc-ecosystem/go-grpc-middleware v1.3.0/go.mod h1:z0ButlSOZa5vEBq9m2m2hlwIgKw+rp3sdCBRoJY+30Y=
 github.com/grpc-ecosystem/grpc-gateway v1.16.0/go.mod h1:BDjrQk3hbvj6Nolgz8mAMFbcEtjT1g+wF4CSlocrBnw=
 github.com/hashicorp/consul/api v1.1.0/go.mod h1:VmuI/Lkw1nC05EYQWNKwWGbkg+FbDBtguAZLlVdkD9Q=
 github.com/hashicorp/consul/sdk v0.1.1/go.mod h1:VKf9jXwCTEY1QZP2MOLRhb5i/I/ssyNV1vwHyQBF0x8=
@@ -329,6 +331,7 @@ github.com/oklog/run v1.0.0/go.mod h1:dlhp/R75TPv97u0XWUtDeV/lRKWPKSdTuV0TZvrmrQ
 github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.8.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/gomega v1.5.0/go.mod h1:ex+gbHU/CVuBBDIJjb2X0qEXbFg53c61hWP/1CpauHY=
+github.com/opentracing/opentracing-go v1.1.0/go.mod h1:UkNAQd3GIcIGf0SeVgPpRdFStlNbqXla1AfSYxPUl2o=
 github.com/pascaldekloe/goe v0.0.0-20180627143212-57f6aae5913c/go.mod h1:lzWF7FIEvWOWxwDKqyGYQf6ZUaNfKdP144TG7ZOy1lc=
 github.com/pascaldekloe/goe v0.1.0/go.mod h1:lzWF7FIEvWOWxwDKqyGYQf6ZUaNfKdP144TG7ZOy1lc=
 github.com/pelletier/go-toml v1.7.0/go.mod h1:vwGMzjaWMwyfHwgIBhI2YUM4fB6nL6lVAvS1LBMMhTE=
@@ -454,14 +457,17 @@ go.opentelemetry.io/otel/sdk/metric v0.25.0/go.mod h1:G4xzj4LvC6xDDSsVXpvRVclQCb
 go.opentelemetry.io/otel/trace v1.2.0 h1:Ys3iqbqZhcf28hHzrm5WAquMkDHNZTUkw7KHbuNjej0=
 go.opentelemetry.io/otel/trace v1.2.0/go.mod h1:N5FLswTubnxKxOJHM7XZC074qpeEdLy3CgAVsdMucK0=
 go.opentelemetry.io/proto/otlp v0.7.0/go.mod h1:PqfVotwruBrMGOCsRd/89rSnXhoiJIqeYNgFYFoEGnI=
+go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE=
 go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
 go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE=
 go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
 go.uber.org/goleak v1.1.11-0.20210813005559-691160354723 h1:sHOAIxRGBp443oHZIPB+HsUGaksVCXVQENPxwTfQdH4=
 go.uber.org/goleak v1.1.11-0.20210813005559-691160354723/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ=
+go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0=
 go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU=
 go.uber.org/multierr v1.7.0 h1:zaiO/rmgFjbmCXdSYJWQcdvOCsthmdaHfr3Gm2Kx4Ec=
 go.uber.org/multierr v1.7.0/go.mod h1:7EAYxJLBy9rStEaz58O2t4Uvip6FSURkq8/ppBp95ak=
+go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q=
 go.uber.org/zap v1.17.0/go.mod h1:MXVU+bhUf/A7Xi2HNOnopQOrmycQ5Ih87HtOu4q5SSo=
 go.uber.org/zap v1.19.1 h1:ue41HOKd1vGURxrmeKIgELGb3jPW9DMUDGtsinblHwI=
 go.uber.org/zap v1.19.1/go.mod h1:j3DNczoxDZroyBnOT1L/Q79cfUMGZxlv/9dzN7SM1rI=
@@ -759,6 +765,7 @@ google.golang.org/genproto v0.0.0-20200228133532-8c2c7df3a383/go.mod h1:55QSHmfG
 google.golang.org/genproto v0.0.0-20200305110556-506484158171/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=
 google.golang.org/genproto v0.0.0-20200312145019-da6875a35672/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=
 google.golang.org/genproto v0.0.0-20200331122359-1ee6d9798940/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=
+google.golang.org/genproto v0.0.0-20200423170343-7949de9c1215/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=
 google.golang.org/genproto v0.0.0-20200430143042-b979b6f78d84/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=
 google.golang.org/genproto v0.0.0-20200511104702-f5ebc3bea380/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=
 google.golang.org/genproto v0.0.0-20200513103714-09dca8ec2884/go.mod h1:55QSHmfGQM9UVYDPBsyGGes0y52j32PQ3BqQfXhyH3c=

service/collector.go

@@ -187,6 +187,8 @@ func (col *Collector) setupConfigurationComponents(ctx context.Context) error {
 		return fmt.Errorf("failed to get logger: %w", err)
 	}
 
+	telemetrylogs.SetGRPCLogger(col.logger, col.cfgW.cfg.Service.Telemetry.Logs.Level)
+
 	col.logger.Info("Applying configuration...")
 
 	col.service, err = newService(&svcSettings{

service/collector_test.go

@@ -23,6 +23,7 @@ import (
 	"net/http"
 	"strconv"
 	"strings"
+	"sync"
 	"syscall"
 	"testing"
 	"time"
@@ -102,10 +103,12 @@ func TestCollector_StartAsGoRoutine(t *testing.T) {
 func TestCollector_Start(t *testing.T) {
 	factories, err := defaultcomponents.Components()
 	require.NoError(t, err)
-
+	var once sync.Once
 	loggingHookCalled := false
 	hook := func(entry zapcore.Entry) error {
-		loggingHookCalled = true
+		once.Do(func() {
+			loggingHookCalled = true
+		})
 		return nil
 	}
 

service/internal/telemetrylogs/logger.go

@@ -15,12 +15,22 @@
 package telemetrylogs // import "go.opentelemetry.io/collector/service/internal/telemetrylogs"
 
 import (
+	grpc_logsettable "github.com/grpc-ecosystem/go-grpc-middleware/logging/settable"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
+	"go.uber.org/zap/zapgrpc"
 
 	"go.opentelemetry.io/collector/config"
 )
 
+var grpcSettableLogger grpc_logsettable.SettableLoggerV2
+
+func init() {
+	// Note: this needs to happen only once and that too before any gRPC calls.
+	// The grpcSettableLogger.Set can be then be called to set any logger after in thread safe fashion.
+	grpcSettableLogger = grpc_logsettable.ReplaceGrpcLoggerV2()
+}
+
 func NewLogger(cfg config.ServiceTelemetryLogs, options []zap.Option) (*zap.Logger, error) {
 	// Copied from NewProductionConfig.
 	zapCfg := &zap.Config{
@@ -45,5 +55,22 @@ func NewLogger(cfg config.ServiceTelemetryLogs, options []zap.Option) (*zap.Logg
 	if err != nil {
 		return nil, err
 	}
+
 	return logger, nil
 }
+
+// SetGRPCLogger replaces grpc logger with logger cloned from baseLogger with exact configuration.
+// The minimum level of gRPC logs is set to WARN should the loglevel of the collector is set to INFO to avoid
+// copious logging from grpc framework.
+func SetGRPCLogger(baseLogger *zap.Logger, loglevel zapcore.Level) {
+	glogger := baseLogger.WithOptions(zap.WrapCore(func(core zapcore.Core) zapcore.Core {
+		var c zapcore.Core
+		if loglevel == zap.InfoLevel {
+			c, _ = zapcore.NewIncreaseLevelCore(core, zap.WarnLevel)
+		} else {
+			c = core
+		}
+		return c.With([]zapcore.Field{zap.Bool("grpc_log", true)})
+	}))
+	grpcSettableLogger.Set(zapgrpc.NewLogger(glogger))
+}

service/internal/telemetrylogs/logger_test.go

@@ -0,0 +1,101 @@
+// Copyright The OpenTelemetry Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//       http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package telemetrylogs
+
+import (
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	"google.golang.org/grpc/grpclog"
+
+	"go.opentelemetry.io/collector/config"
+)
+
+func TestGRPCLogger(t *testing.T) {
+	tests := []struct {
+		name       string
+		cfg        config.ServiceTelemetryLogs
+		infoLogged bool
+		warnLogged bool
+	}{
+		{
+			"collector_info_level_grpc_log_warn",
+			config.ServiceTelemetryLogs{
+				Level:    zapcore.InfoLevel,
+				Encoding: "console",
+			},
+			false,
+			true,
+		},
+		{
+			"collector_debug_level_grpc_log_debug",
+			config.ServiceTelemetryLogs{
+				Level:    zapcore.DebugLevel,
+				Encoding: "console",
+			},
+			true,
+			true,
+		},
+		{
+			"collector_warn_level_grpc_log_warn",
+			config.ServiceTelemetryLogs{
+				Development: false, // this must set the grpc logger to logger
+				Level:       zapcore.WarnLevel,
+				Encoding:    "console",
+			},
+			false,
+			true,
+		},
+	}
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			obsInfo, obsWarn := false, false
+			hook := zap.Hooks(func(entry zapcore.Entry) error {
+				switch entry.Level {
+				case zapcore.InfoLevel:
+					obsInfo = true
+				case zapcore.WarnLevel:
+					obsWarn = true
+				}
+				return nil
+			})
+
+			// create new collector logger
+			logger, err := NewLogger(test.cfg, []zap.Option{hook})
+			assert.NoError(t, err)
+
+			t.Cleanup(func() {
+				defaultLogger, _ := NewLogger(config.ServiceTelemetryLogs{
+					Level:       zapcore.InfoLevel,
+					Development: false,
+					Encoding:    "console",
+				}, nil)
+				SetGRPCLogger(defaultLogger, zapcore.InfoLevel)
+			})
+
+			SetGRPCLogger(logger, test.cfg.Level)
+
+			// write a grpc log
+			grpclog.Info(test.name)
+			grpclog.Warning(test.name)
+
+			// test whether the grpc log has been recorded from collector logger
+			assert.Equal(t, obsInfo, test.infoLogged)
+			assert.Equal(t, obsWarn, test.warnLogged)
+		})
+	}
+}