Skip to content

Enable request log flag support #8958

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
knative-prow-robot merged 11 commits into from
Aug 10, 2020
Merged

Enable request log flag support #8958

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
349c864
enable request log flag
Aug 7, 2020
cbc6aee
fix unit tests
Aug 10, 2020
a5b1ab8
remove activator check
Aug 10, 2020
654235e
use guard clause
Aug 10, 2020
5ad5d27
add test
Aug 10, 2020
632b7fa
fix activator logic
Aug 10, 2020
46c1bde
add request log unit tests
Aug 10, 2020
dc6bc38
fix order
Aug 10, 2020
3cd302c
fix ptr
Aug 10, 2020
8c4693a
minor fixes
Aug 10, 2020
a25e53f
fix test case
Aug 10, 2020
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
12 changes: 11 additions & 1 deletion cmd/activator/request_log.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import (

"go.uber.org/zap"
corev1 "k8s.io/api/core/v1"
"knative.dev/pkg/metrics"
"knative.dev/serving/pkg/activator"
"knative.dev/serving/pkg/apis/serving"
servinglisters "knative.dev/serving/pkg/client/listers/serving/v1"
Expand All @@ -29,7 +30,16 @@ import (

func updateRequestLogFromConfigMap(logger *zap.SugaredLogger, h *pkghttp.RequestLogHandler) func(configMap *corev1.ConfigMap) {
Copy link
Contributor

@julz julz Aug 7, 2020

Choose a reason for hiding this comment

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

this seems like it'll need updates to request_log_test.go

Copy link
Contributor Author

@skonto skonto Aug 10, 2020

Choose a reason for hiding this comment

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

Actually it was queue_test.go, for 0.17 we want things to work as previously so unit tests shouldnt break.

Copy link
Contributor

@julz julz Aug 10, 2020

Choose a reason for hiding this comment

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

queue_test.go failed because of the changes to queue.go. This requires changes to request_log_test.go because it changes the behaviour so should probably at least result in a new row in the table test or something :-).

Copy link
Contributor Author

@skonto skonto Aug 10, 2020 •
edited
Loading

Choose a reason for hiding this comment

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

Yes I was referring to the failures.

Copy link
Contributor

@julz julz Aug 10, 2020

Choose a reason for hiding this comment

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

ah right, gotcha. I was just meaning "we probably need to add a test for the new logic here"

return func(configMap *corev1.ConfigMap) {
newTemplate := configMap.Data["logging.request-log-template"]
obsconfig, err := metrics.NewObservabilityConfigFromConfigMap(configMap)
if err != nil {
logger.Errorw("Failed to get observability configmap.", zap.Error(err), "configmap", configMap)
Copy link
Contributor

@julz julz Aug 7, 2020

Choose a reason for hiding this comment

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

probably better to do this as a guard clause at the top with a return, then the rest of the method can be out-dented

Copy link
Contributor Author

@skonto skonto Aug 10, 2020

Choose a reason for hiding this comment

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

refactored

return
}
Copy link
Contributor

@julz julz Aug 10, 2020

Choose a reason for hiding this comment

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

total nit, but nicer to have a newline after a guard clause I think

Suggested change
}
}


var newTemplate string
if obsconfig.EnableRequestLog {
newTemplate = obsconfig.RequestLogTemplate
}
if err := h.SetTemplate(newTemplate); err != nil {
logger.Errorw("Failed to update the request log template.", zap.Error(err), "template", newTemplate)
} else {
Expand Down
99 changes: 68 additions & 31 deletions cmd/activator/request_log_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -56,48 +56,85 @@ func TestUpdateRequestLogFromConfigMap(t *testing.T) {
}

tests := []struct {
name string
url string
body string
template string
want string
name string
url string
body string
data map[string]string
want string
}{{
name: "empty template",
url: "http://example.com/testpage",
body: "test",
template: "",
want: "",
name: "empty template",
url: "http://example.com/testpage",
body: "test",
data: map[string]string{
"logging.request-log-template": "",
},
want: "",
}, {
name: "template with new line",
url: "http://example.com/testpage",
body: "test",
data: map[string]string{
"logging.request-log-template": "{{.Request.URL}}\n",
},
want: "http://example.com/testpage\n",
}, {
name: "invalid template",
url: "http://example.com",
body: "test",
data: map[string]string{
"logging.request-log-template": "{{}}",
},
want: "http://example.com\n",
}, {
name: "template with new line",
url: "http://example.com/testpage",
body: "test",
template: "{{.Request.URL}}\n",
want: "http://example.com/testpage\n",
name: "revision info",
url: "http://example.com",
body: "test",
data: map[string]string{
"logging.request-log-template": "{{.Revision.Name}}, {{.Revision.Namespace}}, {{.Revision.Service}}, {{.Revision.Configuration}}, {{.Revision.PodName}}, {{.Revision.PodIP}}",
},
want: "testRevision, testNs, testSvc, testConfig, , \n",
}, {
name: "empty template 2",
url: "http://example.com/testpage",
body: "test",
data: map[string]string{
"logging.request-log-template": "",
},
want: "",
}, {
name: "invalid template",
url: "http://example.com",
body: "test",
template: "{{}}",
want: "http://example.com\n",
name: "explicitly enable request logging",
url: "http://example.com/testpage",
body: "test",
data: map[string]string{
"logging.request-log-template": "{{.Request.URL}}\n",
"logging.enable-request-log": "true",
},
want: "http://example.com/testpage\n",
}, {
name: "revision info",
url: "http://example.com",
body: "test",
template: "{{.Revision.Name}}, {{.Revision.Namespace}}, {{.Revision.Service}}, {{.Revision.Configuration}}, {{.Revision.PodName}}, {{.Revision.PodIP}}",
want: "testRevision, testNs, testSvc, testConfig, , \n",
name: "explicitly disable request logging",
url: "http://example.com/testpage",
body: "test",
data: map[string]string{
"logging.request-log-template": "disable_request_log",
"logging.enable-request-log": "false",
},
want: "",
}, {
name: "empty template 2",
url: "http://example.com/testpage",
body: "test",
template: "",
want: "",
name: "explicitly enable request logging with empty template",
url: "http://example.com/testpage",
body: "test",
data: map[string]string{
"logging.request-log-template": "",
"logging.enable-request-log": "true",
},
want: "",
}}

for _, test := range tests {
t.Run(test.name, func(t *testing.T) {
buf.Reset()
cm := &corev1.ConfigMap{}
cm.Data = map[string]string{"logging.request-log-template": test.template}
cm.Data = test.data
(updateRequestLogFromConfigMap(testing2.TestLogger(t), handler))(cm)
resp := httptest.NewRecorder()
req := httptest.NewRequest(http.MethodPost, test.url, bytes.NewBufferString(test.body))
Expand Down
3 changes: 2 additions & 1 deletion cmd/queue/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,7 @@ type config struct {
ServingLoggingConfig string `split_words:"true" required:"true"`
ServingLoggingLevel string `split_words:"true" required:"true"`
ServingRequestLogTemplate string `split_words:"true"` // optional
ServingEnableRequestLog bool `split_words:"true"` // optional
ServingEnableProbeRequestLog bool `split_words:"true"` // optional

// Metrics configuration
Expand Down Expand Up @@ -432,7 +433,7 @@ func buildMetricsServer(promStatReporter *queue.PrometheusStatsReporter, protobu
}

func pushRequestLogHandler(currentHandler http.Handler, env config) http.Handler {
if env.ServingRequestLogTemplate == "" {
if !env.ServingEnableRequestLog {
Copy link
Contributor

@julz julz Aug 10, 2020

Choose a reason for hiding this comment

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

do we want to handle the case where ServiceEnableRequestLog is true but ServingRequestLogTemplate is ""? (e.g. maybe this would happen with default settings in 0.17 and we'd still want to avoid bothering with the request log handler, even though it'll eventually be a no-op?)

Copy link
Contributor Author

@skonto skonto Aug 10, 2020 •
edited
Loading

Choose a reason for hiding this comment

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

@julz in config_overvability.go:

	if raw, ok := configMap.Data["logging.enable-request-log"]; ok {
		if strings.EqualFold(raw, "true") && oc.RequestLogTemplate != "" {
			oc.EnableRequestLog = true
		}
	}

Afaik what you describe cannot happen. We only set it to true internally in 0.17 if the template is not empty.
So even if the configmap has a value of true we push down (activator, QP) a false value.

Copy link
Contributor

@julz julz Aug 10, 2020

Choose a reason for hiding this comment

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

ok cool, sounds good to me then

return currentHandler
}

Expand Down
3 changes: 3 additions & 0 deletions pkg/reconciler/revision/resources/deploy_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -135,6 +135,9 @@ var (
}, {
Name: "SERVING_REQUEST_LOG_TEMPLATE",
Value: "",
}, {
Name: "SERVING_ENABLE_REQUEST_LOG",
Value: "false",
}, {
Name: "SERVING_REQUEST_METRICS_BACKEND",
Value: "",
Expand Down
3 changes: 3 additions & 0 deletions pkg/reconciler/revision/resources/queue.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -311,6 +311,9 @@ func makeQueueContainer(rev *v1.Revision, loggingConfig *logging.Config, tracing
}, {
Name: "SERVING_REQUEST_LOG_TEMPLATE",
Value: observabilityConfig.RequestLogTemplate,
}, {
Name: "SERVING_ENABLE_REQUEST_LOG",
Value: strconv.FormatBool(observabilityConfig.EnableRequestLog),
Copy link
Contributor

@julz julz Aug 7, 2020

Choose a reason for hiding this comment

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

this seems worth adding a quick test for

Copy link
Contributor Author

@skonto skonto Aug 10, 2020

Choose a reason for hiding this comment

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

ok.

}, {
Name: "SERVING_REQUEST_METRICS_BACKEND",
Value: observabilityConfig.RequestMetricsBackend,
Expand Down
18 changes: 18 additions & 0 deletions pkg/reconciler/revision/resources/queue_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -199,6 +199,23 @@ func TestMakeQueueContainer(t *testing.T) {
"SERVING_ENABLE_PROBE_REQUEST_LOG": "true",
})
}),
}, {
name: "disabled request log configuration as env var",
rev: revision("bar", "foo",
withContainers(containers),
withContainerConcurrency(1)),
oc: metrics.ObservabilityConfig{
RequestLogTemplate: "test template",
EnableProbeRequestLog: false,
EnableRequestLog: false,
},
want: queueContainer(func(c *corev1.Container) {
c.Env = env(map[string]string{
"SERVING_REQUEST_LOG_TEMPLATE": "test template",
"SERVING_ENABLE_REQUEST_LOG": "false",
"SERVING_ENABLE_PROBE_REQUEST_LOG": "false",
})
}),
}, {
name: "request metrics backend as env var",
rev: revision("bar", "foo",
Expand Down Expand Up @@ -756,6 +773,7 @@ var defaultEnv = map[string]string{
"TRACING_CONFIG_SAMPLE_RATE": "0",
"TRACING_CONFIG_DEBUG": "false",
"SERVING_REQUEST_LOG_TEMPLATE": "",
"SERVING_ENABLE_REQUEST_LOG": "false",
"SERVING_REQUEST_METRICS_BACKEND": "",
"USER_PORT": strconv.Itoa(v1.DefaultUserPort),
"SYSTEM_NAMESPACE": system.Namespace(),
Expand Down