Skip to content

Structured logging for route controller #888

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
google-prow-robot merged 19 commits into from
May 22, 2018
Merged

Structured logging for route controller #888

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
19 commits
Select commit Hold shift + click to select a range
deb1bb4
Change route controller to use zap structured logging library.
May 12, 2018
835fb1b
Fixes.
May 14, 2018
fdd9e09
Make config failures soft failures and fall back to default logging c…
May 14, 2018
2937b9b
Remove logging folder and put the constants under controller folder.
May 14, 2018
68e58c2
Attach logger into context and pass context around instead of the log…
May 15, 2018
93717a1
Update dependencies.
May 15, 2018
3e86ead
Address PR comments.
May 15, 2018
f46e960
Merge branch 'master' into zap
mdemirhan May 17, 2018
5c80740
Merge branch 'master-upstream' into zap
May 17, 2018
d0354f4
Merge branch 'master' into zap
mdemirhan May 18, 2018
2bd31fd
Changed the logger to return a fallback logger if context doesn't hav…
May 18, 2018
564a068
Merge branch 'master' into zap
mdemirhan May 18, 2018
6d89e28
Merge branch 'master' into zap
mdemirhan May 21, 2018
988d4ee
Updated custom config to match zap production defaults.
May 21, 2018
065d868
Merge branch 'master' into zap
mdemirhan May 21, 2018
319127e
Merge branch 'master' into zap
mdemirhan May 21, 2018
85b8754
Change fallback logger to use a name instead of a separate key.
May 21, 2018
c0cc82d
Merge branch 'master' into zap
mdemirhan May 21, 2018
60db81a
Merge branch 'master' into zap
mdemirhan May 21, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 26 additions & 1 deletion Gopkg.lock
View file
Open in desktop

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 1 addition & 1 deletion cmd/ela-controller/BUILD.bazel
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,10 +13,10 @@ go_library(
"//pkg/controller/revision:go_default_library",
"//pkg/controller/route:go_default_library",
"//pkg/controller/service:go_default_library",
"//pkg/logging:go_default_library",
"//pkg/signals:go_default_library",
"//vendor/github.com/elafros/build/pkg/client/clientset/versioned:go_default_library",
"//vendor/github.com/elafros/build/pkg/client/informers/externalversions:go_default_library",
"//vendor/github.com/golang/glog:go_default_library",
"//vendor/github.com/josephburnett/k8sflag/pkg/k8sflag:go_default_library",
"//vendor/go.opencensus.io/exporter/prometheus:go_default_library",
"//vendor/go.opencensus.io/stats/view:go_default_library",
Expand Down
49 changes: 25 additions & 24 deletions cmd/ela-controller/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,9 +23,9 @@ import (
"time"

"github.com/elafros/elafros/pkg/controller"
"github.com/elafros/elafros/pkg/logging"
"github.com/josephburnett/k8sflag/pkg/k8sflag"

"github.com/golang/glog"
kubeinformers "k8s.io/client-go/informers"
"k8s.io/client-go/kubernetes"
"k8s.io/client-go/tools/clientcmd"
Expand Down Expand Up @@ -63,56 +63,59 @@ var (

loggingEnableVarLogCollection = k8sflag.Bool("logging.enable-var-log-collection", false)
loggingFluentSidecarImage = k8sflag.String("logging.fluentd-sidecar-image", "")
loggingUrlTemplate = k8sflag.String("logging.revision-url-template", "")
loggingURLTemplate = k8sflag.String("logging.revision-url-template", "")
loggingZapCfg = k8sflag.String("logging.ela-controller.zap-config", "")
)

func main() {
flag.Parse()
logger := logging.NewLogger(loggingZapCfg.Get()).Named("ela-controller")
defer logger.Sync()

if loggingEnableVarLogCollection.Get() {
if len(loggingFluentSidecarImage.Get()) != 0 {
glog.Infof("Using fluentd sidecar image: %s", loggingFluentSidecarImage)
logger.Infof("Using fluentd sidecar image: %s", loggingFluentSidecarImage)
} else {
glog.Fatal("missing required flag: -fluentdSidecarImage")
logger.Fatal("missing required flag: -fluentdSidecarImage")
}
}

if loggingUrlTemplate.Get() != "" {
glog.Infof("Using logging url template: %s", loggingUrlTemplate)
if loggingURLTemplate.Get() != "" {
logger.Infof("Using logging url template: %s", loggingURLTemplate)
}

if len(queueSidecarImage) != 0 {
glog.Infof("Using queue sidecar image: %s", queueSidecarImage)
logger.Infof("Using queue sidecar image: %s", queueSidecarImage)
} else {
glog.Fatal("missing required flag: -queueSidecarImage")
logger.Fatal("missing required flag: -queueSidecarImage")
}

if len(autoscalerImage) != 0 {
glog.Infof("Using autoscaler image: %s", autoscalerImage)
logger.Infof("Using autoscaler image: %s", autoscalerImage)
} else {
glog.Fatal("missing required flag: -autoscalerImage")
logger.Fatal("missing required flag: -autoscalerImage")
}
// set up signals so we handle the first shutdown signal gracefully
stopCh := signals.SetupSignalHandler()

cfg, err := clientcmd.BuildConfigFromFlags(masterURL, kubeconfig)
if err != nil {
glog.Fatalf("Error building kubeconfig: %v", err)
logger.Fatalf("Error building kubeconfig: %v", err)
}

kubeClient, err := kubernetes.NewForConfig(cfg)
if err != nil {
glog.Fatalf("Error building kubernetes clientset: %v", err)
logger.Fatalf("Error building kubernetes clientset: %v", err)
}

elaClient, err := clientset.NewForConfig(cfg)
if err != nil {
glog.Fatalf("Error building ela clientset: %v", err)
logger.Fatalf("Error building ela clientset: %v", err)
}

buildClient, err := buildclientset.NewForConfig(cfg)
if err != nil {
glog.Fatalf("Error building build clientset: %v", err)
logger.Fatalf("Error building build clientset: %v", err)
}

kubeInformerFactory := kubeinformers.NewSharedInformerFactory(kubeClient, time.Second*30)
Expand All @@ -121,7 +124,7 @@ func main() {

controllerConfig, err := controller.NewConfig(kubeClient)
if err != nil {
glog.Fatalf("Error loading controller config: %v", err)
logger.Fatalf("Error loading controller config: %v", err)
}

revControllerConfig := revision.ControllerConfig{
Expand All @@ -132,15 +135,15 @@ func main() {

EnableVarLogCollection: loggingEnableVarLogCollection.Get(),
FluentdSidecarImage: loggingFluentSidecarImage.Get(),
LoggingURLTemplate: loggingUrlTemplate.Get(),
LoggingURLTemplate: loggingURLTemplate.Get(),
}

// Build all of our controllers, with the clients constructed above.
// Add new controllers to this array.
controllers := []controller.Interface{
configuration.NewController(kubeClient, elaClient, buildClient, kubeInformerFactory, elaInformerFactory, cfg, *controllerConfig),
revision.NewController(kubeClient, elaClient, kubeInformerFactory, elaInformerFactory, buildInformerFactory, cfg, &revControllerConfig),
route.NewController(kubeClient, elaClient, kubeInformerFactory, elaInformerFactory, cfg, *controllerConfig, autoscaleEnableScaleToZero),
route.NewController(kubeClient, elaClient, kubeInformerFactory, elaInformerFactory, cfg, *controllerConfig, autoscaleEnableScaleToZero, logger),
service.NewController(kubeClient, elaClient, kubeInformerFactory, elaInformerFactory, cfg, *controllerConfig),
}

Expand All @@ -154,16 +157,16 @@ func main() {
// We don't expect this to return until stop is called,
// but if it does, propagate it back.
if runErr := ctrlr.Run(threadsPerController, stopCh); runErr != nil {
glog.Fatalf("Error running controller: %v", runErr)
logger.Fatalf("Error running controller: %v", runErr)
}
}(ctrlr)
}

// Setup the metrics to flow to Prometheus.
glog.Info("Initializing OpenCensus Prometheus exporter.")
logger.Info("Initializing OpenCensus Prometheus exporter.")
promExporter, err := prometheus.NewExporter(prometheus.Options{Namespace: "elafros"})
if err != nil {
glog.Fatalf("failed to create the Prometheus exporter: %v", err)
logger.Fatalf("failed to create the Prometheus exporter: %v", err)
}
view.RegisterExporter(promExporter)
view.SetReportingPeriod(10 * time.Second)
Expand All @@ -172,9 +175,9 @@ func main() {
srv := &http.Server{Addr: metricsScrapeAddr}
http.Handle(metricsScrapePath, promExporter)
go func() {
glog.Info("Starting metrics listener at %s", metricsScrapeAddr)
logger.Infof("Starting metrics listener at %s", metricsScrapeAddr)
if err := srv.ListenAndServe(); err != nil {
glog.Infof("Httpserver: ListenAndServe() finished with error: %v", err)
logger.Infof("Httpserver: ListenAndServe() finished with error: %v", err)
}
}()

Expand All @@ -184,8 +187,6 @@ func main() {
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()
srv.Shutdown(ctx)

glog.Flush()
}

func init() {
Expand Down
26 changes: 26 additions & 0 deletions config/elaconfig.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -88,3 +88,29 @@ data:
logging.revision-url-template: |
http://localhost:8001/api/v1/namespaces/monitoring/services/kibana-logging/proxy/app/kibana#/discover?_a=(query:(match:(kubernetes.labels.elafros-dev%2FrevisionUID:(query:'${REVISION_UID}',type:phrase))))

# Configuration for Elafros controllers
logging.ela-controller.zap-config: |
{
"level": "info",
"development": false,
"sampling": {
"initial": 100,
"thereafter": 100
},
"outputPaths": ["stdout"],
"errorOutputPaths": ["stderr"],
"encoding": "json",
"encoderConfig": {
"timeKey": "",
Copy link
Copy Markdown
Contributor

@grantr grantr May 18, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is timeKey empty? Do we not log timestamps?

Copy link
Copy Markdown
Contributor Author

@mdemirhan mdemirhan May 18, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Kubernetes logging driver already adds a timestamp for logs collected from stdout and stderr. That is why we are omitting it here and preventing dual timestamps in the logs.

"levelKey": "level",
"nameKey": "logger",
"callerKey": "caller",
"messageKey": "msg",
"stacktraceKey": "stacktrace",
"lineEnding": "",
"levelEncoder": "",
"timeEncoder": "",
"durationEncoder": "",
"callerEncoder": ""
}
}
6 changes: 5 additions & 1 deletion pkg/controller/route/BUILD.bazel
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,10 +18,12 @@ go_library(
"//pkg/client/informers/externalversions:go_default_library",
"//pkg/client/listers/ela/v1alpha1:go_default_library",
"//pkg/controller:go_default_library",
"//vendor/github.com/golang/glog:go_default_library",
"//pkg/logging:go_default_library",
"//pkg/logging/logkey:go_default_library",
"//vendor/github.com/josephburnett/k8sflag/pkg/k8sflag:go_default_library",
"//vendor/go.opencensus.io/stats:go_default_library",
"//vendor/go.opencensus.io/tag:go_default_library",
"//vendor/go.uber.org/zap:go_default_library",
"//vendor/k8s.io/api/core/v1:go_default_library",
"//vendor/k8s.io/api/extensions/v1beta1:go_default_library",
"//vendor/k8s.io/apimachinery/pkg/api/errors:go_default_library",
Expand Down Expand Up @@ -51,9 +53,11 @@ go_test(
"//pkg/client/informers/externalversions:go_default_library",
"//pkg/controller:go_default_library",
"//pkg/controller/testing:go_default_library",
"//pkg/logging:go_default_library",
"//vendor/github.com/google/go-cmp/cmp:go_default_library",
"//vendor/github.com/google/go-cmp/cmp/cmpopts:go_default_library",
"//vendor/github.com/josephburnett/k8sflag/pkg/k8sflag:go_default_library",
"//vendor/go.uber.org/zap:go_default_library",
"//vendor/k8s.io/api/core/v1:go_default_library",
"//vendor/k8s.io/apimachinery/pkg/apis/meta/v1:go_default_library",
"//vendor/k8s.io/apimachinery/pkg/runtime:go_default_library",
Expand Down
Loading