k8s liveness check(?) generating session storage log noise
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	Eevans
	Jul 8 2019, 6:36 PM

Description

The liveness check (presumably) is generating the following log output from Kask (session storage service software) on 10 second intervals.

...

2019/07/08 18:30:10 http: TLS handshake error from 10.64.0.247:35706: EOF
2019/07/08 18:30:20 http: TLS handshake error from 10.64.0.247:35784: EOF
2019/07/08 18:30:30 http: TLS handshake error from 10.64.0.247:35862: EOF
2019/07/08 18:30:40 http: TLS handshake error from 10.64.0.247:35940: EOF
2019/07/08 18:30:50 http: TLS handshake error from 10.64.0.247:36018: EOF
2019/07/08 18:31:00 http: TLS handshake error from 10.64.0.247:36096: EOF
2019/07/08 18:31:10 http: TLS handshake error from 10.64.0.247:36174: EOF
2019/07/08 18:31:20 http: TLS handshake error from 10.64.0.247:36252: EOF
...

Possible solutions

Use an HTTPS GET as liveness test
...

Details

Subject	Repo	Branch	Lines +/-
sessionstore: Upgrade to v1.0.5 release	operations/deployment-charts	master	+2 -2
staging/sessionstore: Upgrade image to 2019-10-03-182310-production	operations/deployment-charts	master	+1 -1
Use Logger as Writer for log module	mediawiki/services/kask	master	+29 -3

Customize query in gerrit

Related Objects
Search...

Status	Assigned	Task
Resolved	aaron	T88445 MediaWiki active/active datacenter investigation and work (tracking)
Resolved	Eevans	T206016 Create a service for session storage
Resolved	akosiaris	T227514 k8s liveness check(?) generating session storage log noise

Event Timeline

Eevans created this task.Jul 8 2019, 6:36 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJul 8 2019, 6:36 PM

Eevans triaged this task as Medium priority.Jul 8 2019, 6:37 PM

Eevans mentioned this in T209110: Logging for the session storage service.

Eevans updated the task description. (Show Details)

WDoranWMF edited projects, added Platform Engineering (Session Management Service (CDP2)), Platform Team Workboards (Team 2); removed Platform Engineering.Jul 9 2019, 6:43 PM

WDoranWMF added a parent task: T206016: Create a service for session storage.Jul 18 2019, 8:33 PM

WDoranWMF edited projects, added Platform Engineering (Multi-DC (TEC1)); removed Platform Team Workboards (Team 2), Platform Engineering (Session Management Service (CDP2)).

WDoranWMF moved this task from Multi-DC (TEC1) to mop on the Platform Engineering board.Jul 26 2019, 6:47 PM

WDoranWMF edited projects, added Platform Team Initiatives (Multi-DC (TEC1)); removed Platform Engineering (Multi-DC (TEC1)).

Change 540481 had a related patch set uploaded (by Eevans; owner: Eevans):
[mediawiki/services/kask@master] Use Logger as Writer for log module

https://gerrit.wikimedia.org/r/540481

gerritbot added a project: Patch-For-Review.Oct 2 2019, 8:58 PM

Change 540481 merged by jenkins-bot:
[mediawiki/services/kask@master] Use Logger as Writer for log module

https://gerrit.wikimedia.org/r/540481

Eevans mentioned this in rMSKSdbb8ec9ea896: Use Logger as Writer for log module.Oct 3 2019, 6:20 PM

Change 540660 had a related patch set uploaded (by Eevans; owner: Eevans):
[operations/deployment-charts@master] staging/sessionstore: Upgrade image to 2019-10-03-182310-production

https://gerrit.wikimedia.org/r/540660

Change 540660 merged by jenkins-bot:
[operations/deployment-charts@master] staging/sessionstore: Upgrade image to 2019-10-03-182310-production

https://gerrit.wikimedia.org/r/540660

Eevans mentioned this in rDEPLOYCHARTS2da687d1b87d: staging/sessionstore: Upgrade image to 2019-10-03-182310-production.Oct 3 2019, 7:10 PM

Maintenance_bot removed a project: Patch-For-Review.Oct 3 2019, 7:10 PM

Deployed to staging, the log output now looks like:

{"msg":"Initializing Kask dbb8ec9 (Go version: go1.11.5, Build host: 87a0b5ccf9a6, Timestamp: 2019-10-03T18:23:48+00:00)...","appname":"sessionstore","time":"2019-10-03T19:12:13Z","level":"INFO"}
{"msg":"Starting service as https://0.0.0.0:8081/sessions/v1/","appname":"sessionstore","time":"2019-10-03T19:12:15Z","level":"INFO"}
{"msg":"http: TLS handshake error from 10.64.0.247:56514: EOF","appname":"sessionstore","time":"2019-10-03T19:12:21Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:56614: EOF","appname":"sessionstore","time":"2019-10-03T19:12:31Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:56714: EOF","appname":"sessionstore","time":"2019-10-03T19:12:41Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:56814: EOF","appname":"sessionstore","time":"2019-10-03T19:12:51Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:56914: EOF","appname":"sessionstore","time":"2019-10-03T19:13:01Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:57014: EOF","appname":"sessionstore","time":"2019-10-03T19:13:11Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:57114: EOF","appname":"sessionstore","time":"2019-10-03T19:13:21Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:57214: EOF","appname":"sessionstore","time":"2019-10-03T19:13:31Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:57314: EOF","appname":"sessionstore","time":"2019-10-03T19:13:41Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:57414: EOF","appname":"sessionstore","time":"2019-10-03T19:13:51Z","level":"WARNING"}
{"msg":"http: TLS handshake error from 10.64.0.247:57514: EOF","appname":"sessionstore","time":"2019-10-03T19:14:01Z","level":"WARNING"}

Change 540671 had a related patch set uploaded (by Eevans; owner: Eevans):
[operations/deployment-charts@master] sessionstore: Upgrade to v1.0.5 release

https://gerrit.wikimedia.org/r/540671

Change 540671 merged by Eevans:
[operations/deployment-charts@master] sessionstore: Upgrade to v1.0.5 release

https://gerrit.wikimedia.org/r/540671

Eevans mentioned this in rDEPLOYCHARTS4830f43bccc9: sessionstore: Upgrade to v1.0.5 release.Oct 3 2019, 7:58 PM

Maintenance_bot removed a project: Patch-For-Review.Oct 3 2019, 8:11 PM

I think there were (implicitly) two issues related to this open task: a) a superfluous log message (aka log spam), and b) unstructured log messages. The latter is now solved, the former is not. Possible options for addressing (a):

Adjust the Kask log level so that the superfluous messages aren't logged
Alter the liveness check so that it does not trigger the log message
Do nothing, live with the log spam
...?

#1 would mean either adjusting Kasks log level to ERROR, or lowering the default loglevel of otherwise un-leveled messages (aka those logged by components of Go's standard library using the [[ https://golang.org/pkg/log/ | log ]] module), which is currently WARNING. Neither of these seem very palatable to me, by YMMV.

I 'll be bold and resolve this since we now have fixed b). We can always reopen and evaluate if a) becomes an issue (aka I am going with 3.)

k8s liveness check(?) generating session storage log noiseClosed, ResolvedPublicActions