cmd: Add log parser #590

jodh-intel · 2017-10-04T14:28:40Z

Add a "cc-log-parser" tool that reads multiple logfmt [*] logfiles and
writes their output in time order showing time differences between log
entries.

Fixes #578.

[*] - https://brandur.org/logfmt

Signed-off-by: James O. D. Hunt james.o.hunt@intel.com

jodh-intel · 2017-10-04T14:29:39Z

Note the FIXME but it's benign - we can simply remove one of the time formats once clearcontainers/runtime#652 lands.

clearcontainersbot · 2017-10-04T19:31:29Z

kubernetes qa-failed 👎

devimc · 2017-10-05T13:36:23Z

cmd/cc-log-parser/README.md

+To merge together all logs:
+
+1. Enable global logging in the runtime
+1. Enable debug logging for the proxy.


1. again?

Yeah! 😄 if you uses 1., it triggers markdown to auto-number. If you click on the [View] button, you'll see they get magically updated ;)

ouch! yep sorry

jodh-intel · 2017-10-09T11:05:33Z

The FIXME is now fixed! ;)

clearcontainersbot · 2017-10-09T11:48:16Z

kubernetes qa-passed 👍

jodh-intel · 2017-10-09T14:08:44Z

Hi @iphutch - please could you review the README on this PR (https://github.com/clearcontainers/tests/pull/590/files#diff-c294cba5b0c553706556ef34aa2e7429)?

chavafg · 2017-10-09T16:08:24Z

@jodh-intel, tried this tool and got an error when merging logs from proxy and runtime:

cloud@ubuntu-dev:~$ ./go/bin/cc-log-parser proxy.log runtime.log 
ERROR: agent log entry unpack failed for {TimeDelta:0s Filename:proxy.log Line:5 CCLogEntry:{Time:2017-10-09 07:27:56.798534493 +0000 UTC Pid:0 Level:debug Msg:[    0.317409] brd: module loaded Source:qemu Name: Data:map[vm:7ddcff5ec12e9e2f00ca5c8957b4df794e2c5efe2eb63f3cfea1506fe1ebd64c]}}: invalid character 'b' after top-level value

I have the -log debug option for the cc-proxy service and
enable_debug = true on the runtime configuration.toml

jodh-intel · 2017-10-09T16:23:18Z

Hi @chavafg - thanks for testing. I think the problem you are seeing is because the latest clear-containers.img file doesn't yet have the required fixes. In fact, I'm a bit confused as the latest seems to be 17270 according to:

https://github.com/clearlinux-pkgs/clear-containers-image/commits/master

... but that was from 23 August:

https://download.clearlinux.org/releases/17270/clear/

@jcvenegas, @gorozco1 - am I getting confused here or do we need to update the image (I thought we were doing it weekly as part of the release process)? Which reminds me: clearcontainers/runtime#632 :)

jcvenegas · 2017-10-09T16:49:29Z

@jodh-intel the image was not updated last week, the agent was not tagged for a release, I updated to master anyway on Friday, let me send a PR to updated.

jodh-intel · 2017-10-09T17:01:36Z

Thanks @jcvenegas!

jcvenegas · 2017-10-09T17:02:56Z

@jodh-intel and ouch let me write a docuement about image update.

iphutch

An indentation, wording suggestion, and note. Indentation and wording is all that needs to be changed.

iphutch · 2017-10-09T17:04:02Z

cmd/cc-log-parser/README.md

+
+The primary two logs that are passed to the tool are the [runtime global
+log](https://github.com/clearcontainers/runtime#debugging) and the [proxy
+log](https://github.com/clearcontainers/proxy#debugging).


note:
This wrapping doesn't break anything because it is within the rendered text, however, note that you can ignore 78char rules when it is a link taking you over the max. It's fine as is but should the 78 char mark hit outside of the square brackets, you would wrap text before or after the full
[runtime global log](https://github.com/clearcontainers/runtime#debugging)

iphutch · 2017-10-09T17:06:44Z

cmd/cc-log-parser/README.md

+automatically added to the runtimes global log.
+
+The [agent](https://github.com/clearcontainers/agent) logs are encoded inside
+the proxies log. The tool automatically unpacks these and displays only the


s/The tool/The cc-log-parser tool
OR
s/The tool/cc-log-parser

iphutch · 2017-10-09T17:07:50Z

cmd/cc-log-parser/README.md

+       $ sudo cp /var/lib/clear-containers/runtime/runtime.log ./runtime.log
+       ```
+1. Run the script
+```


indent this code block

Thanks for reviewing @iphutch - branch updated.

clearcontainersbot · 2017-10-10T08:29:47Z

kubernetes qa-passed 👍

clearcontainersbot · 2017-10-10T09:15:36Z

kubernetes qa-passed 👍

iphutch

The README looks great

jodh-intel · 2017-10-11T08:06:24Z

Hi @iphutch - branch updated.

jodh-intel · 2017-10-11T13:37:16Z

Failing on F26 due to the kill_test.go issue:

• Failure [18.183 seconds]
docker kill
/home/jenkins/go/src/github.com/clearcontainers/tests/integration/docker/kill_test.go:129
  killing container
  /home/jenkins/go/src/github.com/clearcontainers/tests/vendor/github.com/onsi/ginkgo/extensions/table/table.go:96
    with '1' signal [It]
    /home/jenkins/go/src/github.com/clearcontainers/tests/vendor/github.com/onsi/ginkgo/extensions/table/table_entry.go:46

    Expected
        <int>: 0
    to equal
        <int>: 1

    /home/jenkins/go/src/github.com/clearcontainers/tests/integration/docker/kill_test.go:95

clearcontainersbot · 2017-10-11T20:16:47Z

kubernetes qa-passed 👍

jodh-intel · 2017-10-12T11:10:32Z

Branch updated now that the shim also produces structured logs (clearcontainers/shim#84).

clearcontainersbot · 2017-10-12T11:44:01Z

kubernetes qa-passed 👍

jodh-intel · 2017-10-12T13:24:43Z

As mentioned on #603, unless you use https://github.com/clearcontainers/osbuilder, you'll need to use clear-18220-containers.img or newer for the agent unpack to work.

jodh-intel · 2017-10-12T13:37:15Z

Found a bug - the agent unpack doesn't work if you have hypervisor debug enabled in the runtime config file, so you'll need to ensure that enable_debug= option is either commented out or set to false.

I'll see if there is a clean way to add a new field for hypervisor output that can be added so cc-log-parser can distinguish hypervisor boot output from other output...

clearcontainersbot · 2017-10-12T13:50:28Z

kubernetes qa-passed 👍

clearcontainersbot · 2017-10-12T15:55:37Z

kubernetes qa-failed 👎

chavafg · 2017-10-12T20:26:20Z

hi @jodh-intel , did you find a way to solve the issue you described above? or should we add in the README a statement to indicate not use with enable_debug = true

jodh-intel · 2017-10-13T11:33:26Z

Hi @chavafg - yes, I've found a way and updated the branch.

To test it fully, you'll need to use the latest shim built from source (./configure && make && sudo make install) and then you'll need to change the runtime config to use that shim:

[shim.cc]
path = "/usr/local/libexec/cc-shim"

But alternatively, just don't pass cc-log-parser a shim.log ;)

clearcontainersbot · 2017-10-13T11:48:03Z

kubernetes qa-passed 👍

clearcontainersbot · 2017-10-13T12:11:05Z

kubernetes qa-passed 👍

Add a "cc-log-parser" tool that reads multiple logfmt [*] logfiles and writes their output in time order showing time differences between log entries. Fixes clearcontainers#578. [*] - https://brandur.org/logfmt Signed-off-by: James O. D. Hunt <james.o.hunt@intel.com>

clearcontainersbot · 2017-10-13T13:23:25Z

kubernetes qa-passed 👍

jodh-intel · 2017-10-16T09:09:35Z

Hi @chavafg - does this work for you now?

chavafg · 2017-10-16T13:58:37Z

Hi @jodh-intel, unfortunately still have issues:

I am running with enable_debug = true using Clear Containers image 18250.

cloud@ubuntu-dev:~$ ~/go/bin/cc-log-parser proxy.log runtime.log shim.log 
ERROR: logfmt syntax error at pos 127 on line 516: invalid quoted value

Taking a look at the log files, the only file which has 516 lines is the proxy, and the error is because of this line:

time="2017-10-16T05:33:51.308880831Z" level=debug msg="Welcome to \\x1b[1;35mClear Linux OS for Intel Architecture\\x1b[0m!" name=cc-proxy pid=1899 source=qemu vm=7276d3d7548b4f72831a3f7f5ea86016bbdfbf1db0dd    c75c923af61c69e17770

clearcontainersbot · 2017-10-21T02:05:16Z

kubernetes qa-failed 👎

clearcontainersbot · 2017-11-23T21:16:39Z

kubernetes qa-passed 👍

clearcontainersbot · 2017-12-14T03:37:50Z

kubernetes qa-passed 👍

clearcontainersbot · 2018-01-09T06:16:28Z

kubernetes qa-passed 👍

jodh-intel · 2018-02-23T17:42:33Z

I'm going to close this PR as the plan is now to move the tool to https://github.com/kata-containers/tests/.

jodh-intel · 2018-03-01T17:22:39Z

Replaced by kata-containers/tests#98.

metrics: Add bidirectional iperf network bandwidth

jodh-intel added the in progress label Oct 4, 2017

devimc reviewed Oct 5, 2017

View reviewed changes

jodh-intel force-pushed the add-log-parser-tool branch from f07205c to 71fcba5 Compare October 9, 2017 11:04

iphutch suggested changes Oct 9, 2017

View reviewed changes

jodh-intel force-pushed the add-log-parser-tool branch 2 times, most recently from 9548146 to 34e9873 Compare October 10, 2017 08:08

iphutch approved these changes Oct 10, 2017

View reviewed changes

jodh-intel force-pushed the add-log-parser-tool branch from 34e9873 to 51fa1ac Compare October 11, 2017 16:35

jodh-intel force-pushed the add-log-parser-tool branch from 51fa1ac to 4fe3add Compare October 12, 2017 11:09

jodh-intel force-pushed the add-log-parser-tool branch from 4fe3add to d87a293 Compare October 12, 2017 13:28

jodh-intel force-pushed the add-log-parser-tool branch from d87a293 to 502bfe2 Compare October 12, 2017 15:26

jodh-intel mentioned this pull request Oct 12, 2017

CI: Show shim log at end of CI run #606

Merged

jodh-intel force-pushed the add-log-parser-tool branch from 502bfe2 to 5c59ecb Compare October 13, 2017 11:25

jodh-intel force-pushed the add-log-parser-tool branch from 5c59ecb to 940627a Compare October 13, 2017 11:36

jodh-intel force-pushed the add-log-parser-tool branch from 940627a to 058c6f7 Compare October 13, 2017 12:41

This was referenced Dec 6, 2017

logging: Ensure journald identifier is simply "cc-proxy" clearcontainers/proxy#181

Merged

Fix network warning message containers/virtcontainers#502

Merged

jodh-intel closed this Feb 23, 2018

jodh-intel removed the in progress label Feb 23, 2018

jodh-intel mentioned this pull request Feb 23, 2018

Add a log parsing tool kata-containers/tests#93

Closed

mcastelino pushed a commit to mcastelino/tests that referenced this pull request Jan 23, 2019

Merge pull request clearcontainers#590 from GabyCT/topic/bidirectional

c26d309

metrics: Add bidirectional iperf network bandwidth

cmd: Add log parser #590

cmd: Add log parser #590

Uh oh!

Conversation

jodh-intel commented Oct 4, 2017

Uh oh!

jodh-intel commented Oct 4, 2017

Uh oh!

clearcontainersbot commented Oct 4, 2017

Uh oh!

devimc Oct 5, 2017

Choose a reason for hiding this comment

Uh oh!

jodh-intel Oct 5, 2017

Choose a reason for hiding this comment

Uh oh!

devimc Oct 5, 2017

Choose a reason for hiding this comment

Uh oh!

jodh-intel commented Oct 9, 2017

Uh oh!

clearcontainersbot commented Oct 9, 2017

Uh oh!

jodh-intel commented Oct 9, 2017

Uh oh!

chavafg commented Oct 9, 2017

Uh oh!

jodh-intel commented Oct 9, 2017

Uh oh!

jcvenegas commented Oct 9, 2017

Uh oh!

jodh-intel commented Oct 9, 2017

Uh oh!

jcvenegas commented Oct 9, 2017

Uh oh!

iphutch left a comment

Choose a reason for hiding this comment

Uh oh!

iphutch Oct 9, 2017

Choose a reason for hiding this comment

Uh oh!

iphutch Oct 9, 2017

Choose a reason for hiding this comment

Uh oh!

iphutch Oct 9, 2017

Choose a reason for hiding this comment

Uh oh!

jodh-intel Oct 10, 2017

Choose a reason for hiding this comment

Uh oh!

clearcontainersbot commented Oct 10, 2017

Uh oh!

clearcontainersbot commented Oct 10, 2017

Uh oh!

iphutch left a comment

Choose a reason for hiding this comment

Uh oh!

jodh-intel commented Oct 11, 2017

Uh oh!

jodh-intel commented Oct 11, 2017

Uh oh!

clearcontainersbot commented Oct 11, 2017

Uh oh!

jodh-intel commented Oct 12, 2017

Uh oh!

clearcontainersbot commented Oct 12, 2017

Uh oh!

jodh-intel commented Oct 12, 2017

Uh oh!

jodh-intel commented Oct 12, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

clearcontainersbot commented Oct 12, 2017

Uh oh!

clearcontainersbot commented Oct 12, 2017

Uh oh!

chavafg commented Oct 12, 2017

Uh oh!

jodh-intel commented Oct 13, 2017

Uh oh!

jodh-intel commented Oct 12, 2017 •

edited

Loading