Job name not being prepended to log lines when using the default format

[mterron]

As per #393 (comment) CP does not add the 'job' name to the log lines.
Log:

2018-01-15T00:03:49.607445593Z 19:M 15 Jan 00:03:49.607 * 10000 changes in 60 seconds. Saving...
2018-01-15T00:03:49.609117243Z 19:M 15 Jan 00:03:49.608 * Background saving started by pid 995
2018-01-15T00:03:49.63182348Z 995:C 15 Jan 00:03:49.631 * DB saved on disk
2018-01-15T00:03:49.709621459Z 19:M 15 Jan 00:03:49.709 * Background saving terminated with success
2018-01-15T00:04:50.078460973Z 19:M 15 Jan 00:04:50.078 * 10000 changes in 60 seconds. Saving...
2018-01-15T00:04:50.081086412Z 19:M 15 Jan 00:04:50.079 * Background saving started by pid 1503
2018-01-15T00:04:50.113329473Z 1503:C 15 Jan 00:04:50.113 * DB saved on disk
2018-01-15T00:04:50.179568328Z 19:M 15 Jan 00:04:50.179 * Background saving terminated with success
2018-01-15T00:05:51.081603133Z 19:M 15 Jan 00:05:51.081 * 10000 changes in 60 seconds. Saving...
2018-01-15T00:05:51.084439175Z 19:M 15 Jan 00:05:51.084 * Background saving started by pid 2011
2018-01-15T00:05:51.107568502Z 2011:C 15 Jan 00:05:51.107 * DB saved on disk
2018-01-15T00:05:51.186578762Z 19:M 15 Jan 00:05:51.186 * Background saving terminated with success
2018-01-15T00:06:52.064484068Z 19:M 15 Jan 00:06:52.064 * 10000 changes in 60 seconds. Saving...
2018-01-15T00:06:52.068001052Z 19:M 15 Jan 00:06:52.067 * Background saving started by pid 2519
2018-01-15T00:06:52.091804705Z 2519:C 15 Jan 00:06:52.091 * DB saved on disk
2018-01-15T00:06:52.169475417Z 19:M 15 Jan 00:06:52.169 * Background saving terminated with success
2018-01-15T00:10:17.052457659Z 19:M 15 Jan 00:10:17.052 * 10000 changes in 60 seconds. Saving...
2018-01-15T00:10:17.058806185Z 19:M 15 Jan 00:10:17.054 * Background saving started by pid 4335
2018-01-15T00:10:17.09716568Z 4335:C 15 Jan 00:10:17.096 * DB saved on disk
2018-01-15T00:10:17.159084084Z 19:M 15 Jan 00:10:17.158 * Background saving terminated with success

I expect to see:

2018-01-15T00:03:49.607445593Z REDIS 19:M 15 Jan 00:03:49.607 * 10000 changes in 60 seconds. Saving...
2018-01-15T00:03:49.609117243Z REDIS 19:M 15 Jan 00:03:49.608 * Background saving started by pid 995
2018-01-15T00:03:49.63182348Z REDIS 995:C 15 Jan 00:03:49.631 * DB saved on disk
...

[jwreagor]

I'm unable to verify where this behavior was removed. It must have been something within logrus itself. Despite not being able to find the old behavior at this time I've got a commit that will output our log fields when we have access to them.

For various log output we attach specific structured logging metadata as "fields". These include the current job name and command PID. My change adds these to the default log output as suggested by this issue.

The new log output looks like this...

2018-02-02T13:06:43.248317284-05:00 control: serving at /tmp/cp-args.socket
2018-02-02T13:06:43.251464677-05:00 goocar 41917 Missing -text option!
2018-02-02T13:06:43.251529017-05:00 goocar exited with error: exit status 127
2018-02-02T13:06:43.265437579-05:00 foobar 41920 2018/02/02 13:06:43 Server is listening on :8084
2018-02-02T13:06:43.267258834-05:00 goocar 41921 Missing -text option!
2018-02-02T13:06:43.270244224-05:00 goocar exited with error: exit status 127
2018-02-02T13:06:43.289841529-05:00 goocar 41939 2018/02/02 13:06:43 Server is listening on :8085
2018-02-02T13:06:53.282645828-05:00 foobar 41920 2018/02/02 13:06:53 localhost:8084 [::1]:51403 "HEAD / HTTP/1.1" 200 6 "curl/7.54.0" 29.119µs
2018-02-02T13:06:53.282713708-05:00 goocar 41939 2018/02/02 13:06:53 localhost:8085 [::1]:51404 "HEAD / HTTP/1.1" 200 6 "curl/7.54.0" 27.758µs
^C2018-02-02T13:06:57.16917649-05:00 foobar 41920 2018/02/02 13:06:57 [INFO] Received termination
2018-02-02T13:06:57.169246685-05:00 goocar 41939 2018/02/02 13:06:57 [INFO] Received termination
2018-02-02T13:06:57.172869592-05:00 goocar exited with error: signal: terminated

In the example above the combination of goocar 41939 and foobar 41920 are the new log fields. The exit status code failures do not include log fields so I can't add them there.

This change set only effects the default log format and not json or text.

Thoughts? @mterron

[jwreagor]

Any thoughts on my PR/change @mterron?

[mterron]

Looks good @cheapRoc

[jwreagor]

Just released in ContainerPilot v3.7.0.