From cfb16f102b6b2844c8fa2371e8dfcf1915713e93 Mon Sep 17 00:00:00 2001 From: Euan Kemp Date: Sat, 19 Nov 2016 22:51:35 -0800 Subject: [PATCH 1/2] godeps: vendor in kmsgparser --- Godeps/Godeps.json | 5 + .../docker/docker/project/CONTRIBUTORS.md | 1 + .../github.com/euank/go-kmsg-parser/LICENSE | 201 ++++++++++++++++++ .../go-kmsg-parser/kmsgparser/kmsgparser.go | 200 +++++++++++++++++ .../euank/go-kmsg-parser/kmsgparser/log.go | 55 +++++ .../prometheus/client_golang/AUTHORS.md | 18 ++ .../prometheus/client_model/AUTHORS.md | 13 ++ 7 files changed, 493 insertions(+) create mode 120000 vendor/github.com/docker/docker/project/CONTRIBUTORS.md create mode 100644 vendor/github.com/euank/go-kmsg-parser/LICENSE create mode 100644 vendor/github.com/euank/go-kmsg-parser/kmsgparser/kmsgparser.go create mode 100644 vendor/github.com/euank/go-kmsg-parser/kmsgparser/log.go create mode 100644 vendor/github.com/prometheus/client_golang/AUTHORS.md create mode 100644 vendor/github.com/prometheus/client_model/AUTHORS.md diff --git a/Godeps/Godeps.json b/Godeps/Godeps.json index 34aa9d1b1b..00dd7a3149 100644 --- a/Godeps/Godeps.json +++ b/Godeps/Godeps.json @@ -303,6 +303,11 @@ "Comment": "v1.0.2", "Rev": "ded5959c0d4e360646dc9e9908cff48666781367" }, + { + "ImportPath": "github.com/euank/go-kmsg-parser/kmsgparser", + "Comment": "v2.0.0", + "Rev": "5ba4d492e455a77d25dcf0d2c4acc9f2afebef4e" + }, { "ImportPath": "github.com/garyburd/redigo/internal", "Rev": "535138d7bcd717d6531c701ef5933d98b1866257" diff --git a/vendor/github.com/docker/docker/project/CONTRIBUTORS.md b/vendor/github.com/docker/docker/project/CONTRIBUTORS.md new file mode 120000 index 0000000000..44fcc63439 --- /dev/null +++ b/vendor/github.com/docker/docker/project/CONTRIBUTORS.md @@ -0,0 +1 @@ +../CONTRIBUTING.md \ No newline at end of file diff --git a/vendor/github.com/euank/go-kmsg-parser/LICENSE b/vendor/github.com/euank/go-kmsg-parser/LICENSE new file mode 100644 index 0000000000..8dada3edaf --- /dev/null +++ b/vendor/github.com/euank/go-kmsg-parser/LICENSE @@ -0,0 +1,201 @@ + Apache License + Version 2.0, January 2004 + http://www.apache.org/licenses/ + + TERMS AND CONDITIONS FOR USE, REPRODUCTION, AND DISTRIBUTION + + 1. Definitions. + + "License" shall mean the terms and conditions for use, reproduction, + and distribution as defined by Sections 1 through 9 of this document. + + "Licensor" shall mean the copyright owner or entity authorized by + the copyright owner that is granting the License. + + "Legal Entity" shall mean the union of the acting entity and all + other entities that control, are controlled by, or are under common + control with that entity. For the purposes of this definition, + "control" means (i) the power, direct or indirect, to cause the + direction or management of such entity, whether by contract or + otherwise, or (ii) ownership of fifty percent (50%) or more of the + outstanding shares, or (iii) beneficial ownership of such entity. + + "You" (or "Your") shall mean an individual or Legal Entity + exercising permissions granted by this License. + + "Source" form shall mean the preferred form for making modifications, + including but not limited to software source code, documentation + source, and configuration files. + + "Object" form shall mean any form resulting from mechanical + transformation or translation of a Source form, including but + not limited to compiled object code, generated documentation, + and conversions to other media types. + + "Work" shall mean the work of authorship, whether in Source or + Object form, made available under the License, as indicated by a + copyright notice that is included in or attached to the work + (an example is provided in the Appendix below). + + "Derivative Works" shall mean any work, whether in Source or Object + form, that is based on (or derived from) the Work and for which the + editorial revisions, annotations, elaborations, or other modifications + represent, as a whole, an original work of authorship. For the purposes + of this License, Derivative Works shall not include works that remain + separable from, or merely link (or bind by name) to the interfaces of, + the Work and Derivative Works thereof. + + "Contribution" shall mean any work of authorship, including + the original version of the Work and any modifications or additions + to that Work or Derivative Works thereof, that is intentionally + submitted to Licensor for inclusion in the Work by the copyright owner + or by an individual or Legal Entity authorized to submit on behalf of + the copyright owner. For the purposes of this definition, "submitted" + means any form of electronic, verbal, or written communication sent + to the Licensor or its representatives, including but not limited to + communication on electronic mailing lists, source code control systems, + and issue tracking systems that are managed by, or on behalf of, the + Licensor for the purpose of discussing and improving the Work, but + excluding communication that is conspicuously marked or otherwise + designated in writing by the copyright owner as "Not a Contribution." + + "Contributor" shall mean Licensor and any individual or Legal Entity + on behalf of whom a Contribution has been received by Licensor and + subsequently incorporated within the Work. + + 2. Grant of Copyright License. Subject to the terms and conditions of + this License, each Contributor hereby grants to You a perpetual, + worldwide, non-exclusive, no-charge, royalty-free, irrevocable + copyright license to reproduce, prepare Derivative Works of, + publicly display, publicly perform, sublicense, and distribute the + Work and such Derivative Works in Source or Object form. + + 3. Grant of Patent License. Subject to the terms and conditions of + this License, each Contributor hereby grants to You a perpetual, + worldwide, non-exclusive, no-charge, royalty-free, irrevocable + (except as stated in this section) patent license to make, have made, + use, offer to sell, sell, import, and otherwise transfer the Work, + where such license applies only to those patent claims licensable + by such Contributor that are necessarily infringed by their + Contribution(s) alone or by combination of their Contribution(s) + with the Work to which such Contribution(s) was submitted. If You + institute patent litigation against any entity (including a + cross-claim or counterclaim in a lawsuit) alleging that the Work + or a Contribution incorporated within the Work constitutes direct + or contributory patent infringement, then any patent licenses + granted to You under this License for that Work shall terminate + as of the date such litigation is filed. + + 4. Redistribution. You may reproduce and distribute copies of the + Work or Derivative Works thereof in any medium, with or without + modifications, and in Source or Object form, provided that You + meet the following conditions: + + (a) You must give any other recipients of the Work or + Derivative Works a copy of this License; and + + (b) You must cause any modified files to carry prominent notices + stating that You changed the files; and + + (c) You must retain, in the Source form of any Derivative Works + that You distribute, all copyright, patent, trademark, and + attribution notices from the Source form of the Work, + excluding those notices that do not pertain to any part of + the Derivative Works; and + + (d) If the Work includes a "NOTICE" text file as part of its + distribution, then any Derivative Works that You distribute must + include a readable copy of the attribution notices contained + within such NOTICE file, excluding those notices that do not + pertain to any part of the Derivative Works, in at least one + of the following places: within a NOTICE text file distributed + as part of the Derivative Works; within the Source form or + documentation, if provided along with the Derivative Works; or, + within a display generated by the Derivative Works, if and + wherever such third-party notices normally appear. The contents + of the NOTICE file are for informational purposes only and + do not modify the License. You may add Your own attribution + notices within Derivative Works that You distribute, alongside + or as an addendum to the NOTICE text from the Work, provided + that such additional attribution notices cannot be construed + as modifying the License. + + You may add Your own copyright statement to Your modifications and + may provide additional or different license terms and conditions + for use, reproduction, or distribution of Your modifications, or + for any such Derivative Works as a whole, provided Your use, + reproduction, and distribution of the Work otherwise complies with + the conditions stated in this License. + + 5. Submission of Contributions. Unless You explicitly state otherwise, + any Contribution intentionally submitted for inclusion in the Work + by You to the Licensor shall be under the terms and conditions of + this License, without any additional terms or conditions. + Notwithstanding the above, nothing herein shall supersede or modify + the terms of any separate license agreement you may have executed + with Licensor regarding such Contributions. + + 6. Trademarks. This License does not grant permission to use the trade + names, trademarks, service marks, or product names of the Licensor, + except as required for reasonable and customary use in describing the + origin of the Work and reproducing the content of the NOTICE file. + + 7. Disclaimer of Warranty. Unless required by applicable law or + agreed to in writing, Licensor provides the Work (and each + Contributor provides its Contributions) on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or + implied, including, without limitation, any warranties or conditions + of TITLE, NON-INFRINGEMENT, MERCHANTABILITY, or FITNESS FOR A + PARTICULAR PURPOSE. You are solely responsible for determining the + appropriateness of using or redistributing the Work and assume any + risks associated with Your exercise of permissions under this License. + + 8. Limitation of Liability. In no event and under no legal theory, + whether in tort (including negligence), contract, or otherwise, + unless required by applicable law (such as deliberate and grossly + negligent acts) or agreed to in writing, shall any Contributor be + liable to You for damages, including any direct, indirect, special, + incidental, or consequential damages of any character arising as a + result of this License or out of the use or inability to use the + Work (including but not limited to damages for loss of goodwill, + work stoppage, computer failure or malfunction, or any and all + other commercial damages or losses), even if such Contributor + has been advised of the possibility of such damages. + + 9. Accepting Warranty or Additional Liability. While redistributing + the Work or Derivative Works thereof, You may choose to offer, + and charge a fee for, acceptance of support, warranty, indemnity, + or other liability obligations and/or rights consistent with this + License. However, in accepting such obligations, You may act only + on Your own behalf and on Your sole responsibility, not on behalf + of any other Contributor, and only if You agree to indemnify, + defend, and hold each Contributor harmless for any liability + incurred by, or claims asserted against, such Contributor by reason + of your accepting any such warranty or additional liability. + + END OF TERMS AND CONDITIONS + + APPENDIX: How to apply the Apache License to your work. + + To apply the Apache License to your work, attach the following + boilerplate notice, with the fields enclosed by brackets "{}" + replaced with your own identifying information. (Don't include + the brackets!) The text should be enclosed in the appropriate + comment syntax for the file format. We also recommend that a + file or class name and description of purpose be included on the + same "printed page" as the copyright notice for easier + identification within third-party archives. + + Copyright {yyyy} {name of copyright owner} + + Licensed under the Apache License, Version 2.0 (the "License"); + you may not use this file except in compliance with the License. + You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. diff --git a/vendor/github.com/euank/go-kmsg-parser/kmsgparser/kmsgparser.go b/vendor/github.com/euank/go-kmsg-parser/kmsgparser/kmsgparser.go new file mode 100644 index 0000000000..df160cad57 --- /dev/null +++ b/vendor/github.com/euank/go-kmsg-parser/kmsgparser/kmsgparser.go @@ -0,0 +1,200 @@ +/* +Copyright 2016 Euan Kemp + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +// Package kmsgparser implements a parser for the Linux `/dev/kmsg` format. +// More information about this format may be found here: +// https://www.kernel.org/doc/Documentation/ABI/testing/dev-kmsg +// Some parts of it are slightly inspired by rsyslog's contrib module: +// https://github.com/rsyslog/rsyslog/blob/v8.22.0/contrib/imkmsg/kmsg.c +package kmsgparser + +import ( + "fmt" + "io" + "os" + "strconv" + "strings" + "syscall" + "time" +) + +// Parser is a parser for the kernel ring buffer found at /dev/kmsg +type Parser interface { + // SeekEnd moves the parser to the end of the kmsg queue. + SeekEnd() error + // Parse provides a channel of messages read from the kernel ring buffer. + // When first called, it will read the existing ringbuffer, after which it will emit new messages as they occur. + Parse() <-chan Message + // SetLogger sets the logger that will be used to report malformed kernel + // ringbuffer lines or unexpected kmsg read errors. + SetLogger(Logger) + // Close closes the underlying kmsg reader for this parser + Close() error +} + +// Message represents a given kmsg logline, including its timestamp (as +// calculated based on offset from boot time), its possibly multi-line body, +// and so on. More information about these mssages may be found here: +// https://www.kernel.org/doc/Documentation/ABI/testing/dev-kmsg +type Message struct { + Priority int + SequenceNumber int + Timestamp time.Time + Message string +} + +func NewParser() (Parser, error) { + f, err := os.Open("/dev/kmsg") + if err != nil { + return nil, err + } + + bootTime, err := getBootTime() + if err != nil { + return nil, err + } + + return &parser{ + log: &StandardLogger{nil}, + kmsgReader: f, + bootTime: bootTime, + }, nil +} + +type ReadSeekCloser interface { + io.ReadCloser + io.Seeker +} + +type parser struct { + log Logger + kmsgReader ReadSeekCloser + bootTime time.Time +} + +func getBootTime() (time.Time, error) { + var sysinfo syscall.Sysinfo_t + err := syscall.Sysinfo(&sysinfo) + if err != nil { + return time.Time{}, fmt.Errorf("could not get boot time: %v", err) + } + // sysinfo only has seconds + return time.Now().Add(-1 * (time.Duration(sysinfo.Uptime) * time.Second)), nil +} + +func (p *parser) SetLogger(log Logger) { + p.log = log +} + +func (p *parser) Close() error { + return p.kmsgReader.Close() +} + +func (p *parser) SeekEnd() error { + _, err := p.kmsgReader.Seek(0, os.SEEK_END) + return err +} + +// Parse will read from the provided reader and provide a channel of messages +// parsed. +// If the provided reader *is not* a proper Linux kmsg device, Parse might not +// behave correctly since it relies on specific behavior of `/dev/kmsg` +// +// A goroutine is created to process the provided reader. The goroutine will +// exit when the given reader is closed. +// Closing the passed in reader will cause the goroutine to exit. +func (p *parser) Parse() <-chan Message { + + output := make(chan Message, 1) + + go func() { + defer close(output) + msg := make([]byte, 8192) + for { + // Each read call gives us one full message. + // https://www.kernel.org/doc/Documentation/ABI/testing/dev-kmsg + n, err := p.kmsgReader.Read(msg) + if err != nil { + if err == syscall.EPIPE { + p.log.Warningf("short read from kmsg; skipping") + continue + } + + if err == io.EOF { + p.log.Infof("kmsg reader closed, shutting down") + return + } + + p.log.Errorf("error reading /dev/kmsg: %v", err) + return + } + + msgStr := string(msg[:n]) + + message, err := p.parseMessage(msgStr) + if err != nil { + p.log.Warningf("unable to parse kmsg message %q: %v", msgStr, err) + continue + } + + output <- message + } + }() + + return output +} + +func (p *parser) parseMessage(input string) (Message, error) { + // Format: + // PRIORITY,SEQUENCE_NUM,TIMESTAMP,-;MESSAGE + parts := strings.SplitN(input, ";", 2) + if len(parts) != 2 { + return Message{}, fmt.Errorf("invalid kmsg; must contain a ';'") + } + + metadata, message := parts[0], parts[1] + + metadataParts := strings.Split(metadata, ",") + if len(metadataParts) < 3 { + return Message{}, fmt.Errorf("invalid kmsg: must contain at least 3 ',' separated pieces at the start") + } + + priority, sequence, timestamp := metadataParts[0], metadataParts[1], metadataParts[2] + + prioNum, err := strconv.Atoi(priority) + if err != nil { + return Message{}, fmt.Errorf("could not parse %q as priority: %v", priority, err) + } + + sequenceNum, err := strconv.Atoi(sequence) + if err != nil { + return Message{}, fmt.Errorf("could not parse %q as sequence number: %v", priority, err) + } + + timestampUsFromBoot, err := strconv.ParseInt(timestamp, 10, 64) + if err != nil { + return Message{}, fmt.Errorf("could not parse %q as timestamp: %v", priority, err) + } + // timestamp is offset in microsecond from boottime. + msgTime := p.bootTime.Add(time.Duration(timestampUsFromBoot) * time.Microsecond) + + return Message{ + Priority: prioNum, + SequenceNumber: sequenceNum, + Timestamp: msgTime, + Message: message, + }, nil +} diff --git a/vendor/github.com/euank/go-kmsg-parser/kmsgparser/log.go b/vendor/github.com/euank/go-kmsg-parser/kmsgparser/log.go new file mode 100644 index 0000000000..6ea2d96dfe --- /dev/null +++ b/vendor/github.com/euank/go-kmsg-parser/kmsgparser/log.go @@ -0,0 +1,55 @@ +/* +Copyright 2016 Euan Kemp + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package kmsgparser + +import stdlog "log" + +// Logger is a glog compatible logging interface +// The StandardLogger struct can be used to wrap a log.Logger from the golang +// "log" package to create a standard a logger fulfilling this interface as +// well. +type Logger interface { + Warningf(string, ...interface{}) + Infof(string, ...interface{}) + Errorf(string, ...interface{}) +} + +// StandardLogger adapts the "log" package's Logger interface to be a Logger +type StandardLogger struct { + *stdlog.Logger +} + +func (s *StandardLogger) Warningf(fmt string, args ...interface{}) { + if s.Logger == nil { + return + } + s.Logger.Printf("[WARNING] "+fmt, args) +} + +func (s *StandardLogger) Infof(fmt string, args ...interface{}) { + if s.Logger == nil { + return + } + s.Logger.Printf("[INFO] "+fmt, args) +} + +func (s *StandardLogger) Errorf(fmt string, args ...interface{}) { + if s.Logger == nil { + return + } + s.Logger.Printf("[INFO] "+fmt, args) +} diff --git a/vendor/github.com/prometheus/client_golang/AUTHORS.md b/vendor/github.com/prometheus/client_golang/AUTHORS.md new file mode 100644 index 0000000000..b67a4f5a41 --- /dev/null +++ b/vendor/github.com/prometheus/client_golang/AUTHORS.md @@ -0,0 +1,18 @@ +The Prometheus project was started by Matt T. Proud (emeritus) and +Julius Volz in 2012. + +Maintainers of this repository: + +* Björn Rabenstein + +The following individuals have contributed code to this repository +(listed in alphabetical order): + +* Bernerd Schaefer +* Björn Rabenstein +* Daniel Bornkessel +* Jeff Younker +* Julius Volz +* Matt T. Proud +* Tobias Schmidt + diff --git a/vendor/github.com/prometheus/client_model/AUTHORS.md b/vendor/github.com/prometheus/client_model/AUTHORS.md new file mode 100644 index 0000000000..e8b3efa6ac --- /dev/null +++ b/vendor/github.com/prometheus/client_model/AUTHORS.md @@ -0,0 +1,13 @@ +The Prometheus project was started by Matt T. Proud (emeritus) and +Julius Volz in 2012. + +Maintainers of this repository: + +* Björn Rabenstein + +The following individuals have contributed code to this repository +(listed in alphabetical order): + +* Björn Rabenstein +* Matt T. Proud +* Tobias Schmidt From 95f9c8c86fe68ee709805d9fb4e5f745e1a03002 Mon Sep 17 00:00:00 2001 From: Euan Kemp Date: Sat, 19 Nov 2016 22:47:43 -0800 Subject: [PATCH 2/2] oomparser: update to use kmsg based parser This provides much more robust support for kernel logs via accessing the `/dev/kmsg` interface to them directly. --- utils/oomparser/containerOomExampleLog.txt | 44 --- utils/oomparser/oomparser.go | 158 ++------- utils/oomparser/oomparser_test.go | 375 ++++++++++++++++++--- utils/oomparser/systemOomExampleLog.txt | 362 -------------------- 4 files changed, 371 insertions(+), 568 deletions(-) delete mode 100644 utils/oomparser/containerOomExampleLog.txt delete mode 100644 utils/oomparser/systemOomExampleLog.txt diff --git a/utils/oomparser/containerOomExampleLog.txt b/utils/oomparser/containerOomExampleLog.txt deleted file mode 100644 index be6632e641..0000000000 --- a/utils/oomparser/containerOomExampleLog.txt +++ /dev/null @@ -1,44 +0,0 @@ -Jan 5 15:19:01 CRON[14500]: (root) CMD (touch /var/run/crond.sittercheck) -Jan 5 15:19:04 cookie_monster[1249]: uid 0, pid 14504, "/var/lib/certs/machine_cert.crt" accessed by exe "/usr/bin/nsscacheclient", cwd "/root", comm "/usr/bin/nsscacheclient" -Jan 5 15:19:04 cookie_monster[1249]: uid 0, pid 14504, "/var/lib/certs/machine_cert.key" accessed by exe "/usr/bin/nsscacheclient", cwd "/root", comm "/usr/bin/nsscacheclient" -Jan 5 15:19:05 nsscacheclient[14504]: SUCCESS: Completed run (v29/c20 rtime:0.334299 utime:0.136923 stime:0.011736 maxrss:5260k dials:1 sent:1793 rcvd:5143). -Jan 5 15:19:27 kernel: [ 5864.708440] memorymonster invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=0 -Jan 5 15:19:27 kernel: [ 5864.708443] memorymonster cpuset=/ mems_allowed=0 -Jan 5 15:19:27 kernel: [ 5864.708446] CPU: 5 PID: 13536 Comm: memorymonster Tainted: P OX 3.13.0-43-generic #72-Ubuntu -Jan 5 15:19:27 kernel: [ 5864.708447] Hardware name: Hewlett-Packard HP Z420 Workstation/1589, BIOS J61 v03.65 12/19/2013 -Jan 5 15:19:27 kernel: [ 5864.708448] ffff88072ae10800 ffff8807a4835c48 ffffffff81720bf6 ffff8807a8e86000 -Jan 5 15:19:27 kernel: [ 5864.708451] ffff8807a4835cd0 ffffffff8171b4b1 0000000000000246 ffff88072ae10800 -Jan 5 15:19:27 kernel: [ 5864.708453] ffff8807a4835c90 ffff8807a4835ca0 ffffffff811522a7 0000000000000001 -Jan 5 15:19:27 kernel: [ 5864.708455] Call Trace: -Jan 5 15:19:27 kernel: [ 5864.708460] [] dump_stack+0x45/0x56 -Jan 5 15:19:27 kernel: [ 5864.708463] [] dump_header+0x7f/0x1f1 -Jan 5 15:19:27 kernel: [ 5864.708465] [] ? find_lock_task_mm+0x27/0x70 -Jan 5 15:19:27 kernel: [ 5864.708467] [] oom_kill_process+0x1ce/0x330 -Jan 5 15:19:27 kernel: [ 5864.708470] [] ? security_capable_noaudit+0x15/0x20 -Jan 5 15:19:27 kernel: [ 5864.708474] [] mem_cgroup_oom_synchronize+0x51c/0x560 -Jan 5 15:19:27 kernel: [ 5864.708476] [] ? mem_cgroup_charge_common+0xa0/0xa0 -Jan 5 15:19:27 kernel: [ 5864.708478] [] pagefault_out_of_memory+0x14/0x80 -Jan 5 15:19:27 kernel: [ 5864.708480] [] mm_fault_error+0x8e/0x180 -Jan 5 15:19:27 kernel: [ 5864.708482] [] __do_page_fault+0x4a1/0x560 -Jan 5 15:19:27 kernel: [ 5864.708485] [] ? set_next_entity+0x95/0xb0 -Jan 5 15:19:27 kernel: [ 5864.708489] [] ? __switch_to+0x169/0x4c0 -Jan 5 15:19:27 kernel: [ 5864.708490] [] do_page_fault+0x1a/0x70 -Jan 5 15:19:27 kernel: [ 5864.708492] [] page_fault+0x28/0x30 -Jan 5 15:19:27 kernel: [ 5864.708493] Task in /mem2 killed as a result of limit of /mem2 -Jan 5 15:19:27 kernel: [ 5864.708495] memory: usage 980kB, limit 980kB, failcnt 4152239 -Jan 5 15:19:27 kernel: [ 5864.708495] memory+swap: usage 0kB, limit 18014398509481983kB, failcnt 0 -Jan 5 15:19:27 kernel: [ 5864.708496] kmem: usage 0kB, limit 18014398509481983kB, failcnt 0 -Jan 5 15:19:27 kernel: [ 5864.708497] Memory cgroup stats for /mem2: cache:0KB rss:980KB rss_huge:0KB mapped_file:0KB writeback:20KB inactive_anon:560KB active_anon:420KB inactive_file:0KB active_file:0KB unevictable:0KB -Jan 5 15:19:27 kernel: [ 5864.708505] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name -Jan 5 15:19:27 kernel: [ 5864.708600] [13536] 275858 13536 8389663 343 16267 8324326 0 memorymonster -Jan 5 15:19:27 kernel: [ 5864.708607] Memory cgroup out of memory: Kill process 13536 (memorymonster) score 996 or sacrifice child -Jan 5 15:19:27 kernel: [ 5864.708608] Killed process 13536 (memorymonster) total-vm:33558652kB, anon-rss:920kB, file-rss:452kB -Jan 5 15:20:01 CRON[14608]: (root) CMD (touch /var/run/crond.sittercheck) -Jan 5 15:20:01 CRON[14609]: (root) CMD (/usr/bin/alarm 6000 /usr/share/update-notifier/reevaluate.py) -Jan 5 15:20:01 CRON[14610]: (root) CMD (/usr/bin/corp_cronwrap -j 80 -t 600 -A -K -L -l 'nsscache-client' /usr/bin/nsscacheclient all) -Jan 5 15:20:01 /usr/bin/lock: called by /bin/bash for . uid 0, euid 0. -Jan 5 15:21:01 CRON[14639]: (root) CMD (touch /var/run/crond.sittercheck) -Jan 5 15:21:05 cookie_monster[1249]: uid 0, pid 14643, "/var/lib/certs/machine_cert.crt" accessed by exe "/usr/bin/nsscacheclient", cwd "/root", comm "/usr/bin/nsscacheclient" -Jan 5 15:21:05 cookie_monster[1249]: uid 0, pid 14643, "/var/lib/certs/machine_cert.key" accessed by exe "/usr/bin/nsscacheclient", cwd "/root", comm "/usr/bin/nsscacheclient" -Jan 5 15:21:05 nsscacheclient[14643]: auto.auto(no change) time:0.042264697000000004 retries:0 -Jan 5 15:21:05 nsscacheclient[14643]: auto.home(63c07d09->8686499b write:3631382) time:0.318774602 retries:0 \ No newline at end of file diff --git a/utils/oomparser/oomparser.go b/utils/oomparser/oomparser.go index e9e6041cc5..184cdd73fd 100644 --- a/utils/oomparser/oomparser.go +++ b/utils/oomparser/oomparser.go @@ -15,31 +15,26 @@ package oomparser import ( - "bufio" - "fmt" - "io" - "os/exec" "path" "regexp" "strconv" - "syscall" "time" - "github.com/google/cadvisor/utils" - "github.com/google/cadvisor/utils/tail" + "github.com/euank/go-kmsg-parser/kmsgparser" "github.com/golang/glog" ) var ( containerRegexp = regexp.MustCompile(`Task in (.*) killed as a result of limit of (.*)`) - lastLineRegexp = regexp.MustCompile(`(^[A-Z][a-z]{2} .*[0-9]{1,2} [0-9]{1,2}:[0-9]{2}:[0-9]{2}) .* Killed process ([0-9]+) \((.+)\)`) + lastLineRegexp = regexp.MustCompile(`Killed process ([0-9]+) \((.+)\)`) firstLineRegexp = regexp.MustCompile(`invoked oom-killer:`) ) -// struct to hold file from which we obtain OomInstances +// OomParser wraps a kmsgparser in order to extract OOM events from the +// individual kernel ring buffer messages. type OomParser struct { - ioreader *bufio.Reader + parser kmsgparser.Parser } // struct that contains information related to an OOM kill instance @@ -76,20 +71,13 @@ func getProcessNamePid(line string, currentOomInstance *OomInstance) (bool, erro if reList == nil { return false, nil } - const longForm = "Jan _2 15:04:05 2006" - stringYear := strconv.Itoa(time.Now().Year()) - linetime, err := time.ParseInLocation(longForm, reList[1]+" "+stringYear, time.Local) - if err != nil { - return false, err - } - currentOomInstance.TimeOfDeath = linetime - pid, err := strconv.Atoi(reList[2]) + pid, err := strconv.Atoi(reList[1]) if err != nil { return false, err } currentOomInstance.Pid = pid - currentOomInstance.ProcessName = reList[3] + currentOomInstance.ProcessName = reList[2] return true, nil } @@ -102,135 +90,61 @@ func checkIfStartOfOomMessages(line string) bool { return false } -// reads the file and sends only complete lines over a channel to analyzeLines. -// Should prevent EOF errors that occur when lines are read before being fully -// written to the log. It reads line by line splitting on -// the "\n" character. -func readLinesFromFile(lineChannel chan string, ioreader *bufio.Reader) error { - linefragment := "" - var line string - var err error - for true { - line, err = ioreader.ReadString('\n') - if err != nil && err != io.EOF { - glog.Errorf("exiting analyzeLinesHelper with error %v", err) - close(lineChannel) - break - } - if line == "" { - time.Sleep(100 * time.Millisecond) - continue - } - if err == nil { - lineChannel <- linefragment + line - linefragment = "" - } else { // err == io.EOF - linefragment += line - } - } - return err -} +// StreamOoms writes to a provided a stream of OomInstance objects representing +// OOM events that are found in the logs. +// It will block and should be called from a goroutine. +func (self *OomParser) StreamOoms(outStream chan<- *OomInstance) { + kmsgEntries := self.parser.Parse() + defer self.parser.Close() -// Calls goroutine for readLinesFromFile, which feeds it complete lines. -// Lines are checked against a regexp to check for the pid, process name, etc. -// At the end of an oom message group, StreamOoms adds the new oomInstance to -// oomLog -func (self *OomParser) StreamOoms(outStream chan *OomInstance) { - lineChannel := make(chan string, 10) - go func() { - readLinesFromFile(lineChannel, self.ioreader) - }() - - for line := range lineChannel { - in_oom_kernel_log := checkIfStartOfOomMessages(line) + for msg := range kmsgEntries { + in_oom_kernel_log := checkIfStartOfOomMessages(msg.Message) if in_oom_kernel_log { oomCurrentInstance := &OomInstance{ ContainerName: "/", + TimeOfDeath: msg.Timestamp, } - for line := range lineChannel { - err := getContainerName(line, oomCurrentInstance) + for msg := range kmsgEntries { + err := getContainerName(msg.Message, oomCurrentInstance) if err != nil { glog.Errorf("%v", err) } - finished, err := getProcessNamePid(line, oomCurrentInstance) + finished, err := getProcessNamePid(msg.Message, oomCurrentInstance) if err != nil { glog.Errorf("%v", err) } if finished { + oomCurrentInstance.TimeOfDeath = msg.Timestamp break } } outStream <- oomCurrentInstance } } - glog.Infof("exiting analyzeLines. OOM events will not be reported.") + // Should not happen + glog.Errorf("exiting analyzeLines. OOM events will not be reported.") } -func callJournalctl() (io.ReadCloser, error) { - cmd := exec.Command("journalctl", "-k", "-f") - cmd.SysProcAttr = &syscall.SysProcAttr{ - Pdeathsig: syscall.SIGKILL, - } - readcloser, err := cmd.StdoutPipe() +// initializes an OomParser object. Returns an OomParser object and an error. +func New() (*OomParser, error) { + parser, err := kmsgparser.NewParser() if err != nil { return nil, err } - if err := cmd.Start(); err != nil { - return nil, err - } - return readcloser, err + parser.SetLogger(glogAdapter{}) + return &OomParser{parser: parser}, nil } -func trySystemd() (*OomParser, error) { - readcloser, err := callJournalctl() - if err != nil { - return nil, err - } - glog.Infof("oomparser using systemd") - return &OomParser{ - ioreader: bufio.NewReader(readcloser), - }, nil -} +type glogAdapter struct{} -// List of possible kernel log files. These are prioritized in order so that -// we will use the first one that is available. -var kernelLogFiles = []string{"/var/log/kern.log", "/var/log/messages", "/var/log/syslog"} - -// looks for system files that contain kernel messages and if one is found, sets -// the systemFile attribute of the OomParser object -func getLogFile() (string, error) { - for _, logFile := range kernelLogFiles { - if utils.FileExists(logFile) { - glog.Infof("OOM parser using kernel log file: %q", logFile) - return logFile, nil - } - } - return "", fmt.Errorf("unable to find any kernel log file available from our set: %v", kernelLogFiles) -} +var _ kmsgparser.Logger = glogAdapter{} -func tryLogFile() (*OomParser, error) { - logFile, err := getLogFile() - if err != nil { - return nil, err - } - tail, err := tail.NewTail(logFile) - if err != nil { - return nil, err - } - return &OomParser{ - ioreader: bufio.NewReader(tail), - }, nil +func (glogAdapter) Infof(format string, args ...interface{}) { + glog.V(4).Infof(format, args) } - -// initializes an OomParser object. Returns an OomParser object and an error. -func New() (*OomParser, error) { - parser, err := trySystemd() - if err == nil { - return parser, nil - } - parser, err = tryLogFile() - if err == nil { - return parser, nil - } - return nil, err +func (glogAdapter) Warningf(format string, args ...interface{}) { + glog.Infof(format, args) +} +func (glogAdapter) Errorf(format string, args ...interface{}) { + glog.Warningf(format, args) } diff --git a/utils/oomparser/oomparser_test.go b/utils/oomparser/oomparser_test.go index ccf1864a02..3fb75d3627 100644 --- a/utils/oomparser/oomparser_test.go +++ b/utils/oomparser/oomparser_test.go @@ -15,19 +15,17 @@ package oomparser import ( - "bufio" "fmt" - "os" - "strconv" "testing" "time" + "github.com/euank/go-kmsg-parser/kmsgparser" "github.com/stretchr/testify/assert" ) -const startLine = "Jan 21 22:01:49 localhost kernel: [62278.816267] ruby invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0" -const endLine = "Jan 21 22:01:49 localhost kernel: [62279.421192] Killed process 19667 (evil-program2) total-vm:1460016kB, anon-rss:1414008kB, file-rss:4kB" -const containerLine = "Jan 26 14:10:07 kateknister0.mtv.corp.google.com kernel: [1814368.465205] Task in /mem2 killed as a result of limit of /mem3" +const startLine = "ruby invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0" +const endLine = "Killed process 19667 (evil-program2) total-vm:1460016kB, anon-rss:1414008kB, file-rss:4kB" +const containerLine = "Task in /mem2 killed as a result of limit of /mem3" const containerLogFile = "containerOomExampleLog.txt" const systemLogFile = "systemOomExampleLog.txt" @@ -94,9 +92,6 @@ func TestGetProcessNamePid(t *testing.T) { t.Errorf("bad line fed to getProcessNamePid should return false but returned %v", couldParseLine) } - const longForm = "Jan _2 15:04:05 2006" - stringYear := strconv.Itoa(time.Now().Year()) - correctTime, err := time.ParseInLocation(longForm, fmt.Sprintf("Jan 21 22:01:49 %s", stringYear), time.Local) couldParseLine, err = getProcessNamePid(endLine, currentOomInstance) if err != nil { t.Errorf("good line fed to getProcessNamePid should yield no error, but had error %v", err) @@ -110,9 +105,6 @@ func TestGetProcessNamePid(t *testing.T) { if currentOomInstance.Pid != 19667 { t.Errorf("getProcessNamePid should have set PID to 19667, not %d", currentOomInstance.Pid) } - if !correctTime.Equal(currentOomInstance.TimeOfDeath) { - t.Errorf("getProcessNamePid should have set date to %v, not %v", correctTime, currentOomInstance.TimeOfDeath) - } } func TestCheckIfStartOfMessages(t *testing.T) { @@ -137,42 +129,345 @@ func TestLastLineRegex(t *testing.T) { } } -func TestStreamOomsContainer(t *testing.T) { - expectedContainerOomInstance := createExpectedContainerOomInstance(t) - helpTestStreamOoms(expectedContainerOomInstance, containerLogFile, t) -} +func TestStreamOOMs(t *testing.T) { + mockMsgs := make(chan kmsgparser.Message) + p := &OomParser{ + parser: &mockKmsgParser{ + messages: mockMsgs, + }, + } -func TestStreamOomsSystem(t *testing.T) { - expectedSystemOomInstance := createExpectedSystemOomInstance(t) - helpTestStreamOoms(expectedSystemOomInstance, systemLogFile, t) -} + oomsOut := make(chan *OomInstance) -func helpTestStreamOoms(oomCheckInstance *OomInstance, sysFile string, t *testing.T) { - outStream := make(chan *OomInstance) - oomLog := mockOomParser(sysFile, t) - timeout := make(chan bool, 1) go func() { - time.Sleep(1 * time.Second) - timeout <- true + p.StreamOoms(oomsOut) }() - go oomLog.StreamOoms(outStream) + writeAll := func(m []string, t time.Time) { + for _, msg := range m { + mockMsgs <- kmsgparser.Message{ + Message: msg, + Timestamp: t, + } + } + } - select { - case oomInstance := <-outStream: - assert.Equal(t, oomCheckInstance, oomInstance) - case <-timeout: - t.Error( - "timeout happened before oomInstance was found in test file") + type in struct { + msgs []string + time time.Time } -} -func mockOomParser(sysFile string, t *testing.T) *OomParser { - file, err := os.Open(sysFile) - if err != nil { - t.Errorf("had an error opening file: %v", err) + testTime := time.Unix(0xf331f4ee, 0) + testTime2 := time.Unix(0xfa51f001, 0) + testPairs := []struct { + in []in + out []*OomInstance + }{ + { + in: []in{{ + time: testTime, + msgs: []string{ + "memorymonster invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=0", + "memorymonster cpuset=/ mems_allowed=0", + "CPU: 5 PID: 13536 Comm: memorymonster Tainted: P OX 3.13.0-43-generic #72-Ubuntu", + "Hardware name: Hewlett-Packard HP Z420 Workstation/1589, BIOS J61 v03.65 12/19/2013", + " ffff88072ae10800 ffff8807a4835c48 ffffffff81720bf6 ffff8807a8e86000", + " ffff8807a4835cd0 ffffffff8171b4b1 0000000000000246 ffff88072ae10800", + " ffff8807a4835c90 ffff8807a4835ca0 ffffffff811522a7 0000000000000001", + "Call Trace:", + " [] dump_stack+0x45/0x56", + " [] dump_header+0x7f/0x1f1", + " [] ? find_lock_task_mm+0x27/0x70", + " [] oom_kill_process+0x1ce/0x330", + " [] ? security_capable_noaudit+0x15/0x20", + " [] mem_cgroup_oom_synchronize+0x51c/0x560", + " [] ? mem_cgroup_charge_common+0xa0/0xa0", + " [] pagefault_out_of_memory+0x14/0x80", + " [] mm_fault_error+0x8e/0x180", + " [] __do_page_fault+0x4a1/0x560", + " [] ? set_next_entity+0x95/0xb0", + " [] ? __switch_to+0x169/0x4c0", + " [] do_page_fault+0x1a/0x70", + " [] page_fault+0x28/0x30", + "Task in /mem2 killed as a result of limit of /mem2", + "memory: usage 980kB, limit 980kB, failcnt 4152239", + "memory+swap: usage 0kB, limit 18014398509481983kB, failcnt 0", + "kmem: usage 0kB, limit 18014398509481983kB, failcnt 0", + "Memory cgroup stats for /mem2: cache:0KB rss:980KB rss_huge:0KB mapped_file:0KB writeback:20KB inactive_anon:560KB active_anon:420KB inactive_file:0KB active_file:0KB unevictable:0KB", + "[ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name", + "[13536] 275858 13536 8389663 343 16267 8324326 0 memorymonster", + "Memory cgroup out of memory: Kill process 13536 (memorymonster) score 996 or sacrifice child", + "Killed process 13536 (memorymonster) total-vm:33558652kB, anon-rss:920kB, file-rss:452kB", + }, + }}, + out: []*OomInstance{{ + TimeOfDeath: testTime, + ContainerName: "/mem2", + ProcessName: "memorymonster", + Pid: 13536, + VictimContainerName: "/mem2", + }}, + }, + { + in: []in{{ + time: testTime, + msgs: []string{ + "badsysprogram invoked oom-killer: gfp_mask=0x280da, order=0, oom_score_adj=0", + "badsysprogram cpuset=/ mems_allowed=0", + "CPU: 0 PID: 1532 Comm: badsysprogram Not tainted 3.13.0-27-generic #50-Ubuntu", + "Hardware name: Google Google, BIOS Google 01/01/2011", + " 0000000000000000 ffff880069715a90 ffffffff817199c4 ffff8800680d8000", + " ffff880069715b18 ffffffff817142ff 0000000000000000 0000000000000000", + " 0000000000000000 0000000000000000 0000000000000000 0000000000000000", + "Call Trace:", + " [] dump_stack+0x45/0x56", + " [] dump_header+0x7f/0x1f1", + " [] oom_kill_process+0x1ce/0x330", + " [] ? security_capable_noaudit+0x15/0x20", + " [] out_of_memory+0x414/0x450", + " [] __alloc_pages_nodemask+0xa87/0xb20", + " [] alloc_pages_vma+0x9a/0x140", + " [] handle_mm_fault+0xb2b/0xf10", + " [] __do_page_fault+0x184/0x560", + " [] ? sched_clock+0x9/0x10", + " [] ? sched_clock_local+0x1d/0x80", + " [] ? acct_account_cputime+0x1c/0x20", + " [] ? account_user_time+0x8b/0xa0", + " [] ? vtime_account_user+0x54/0x60", + " [] do_page_fault+0x1a/0x70", + " [] page_fault+0x28/0x30", + "Mem-Info:", + "Node 0 DMA per-cpu:", + "CPU 0: hi: 0, btch: 1 usd: 0", + "Node 0 DMA32 per-cpu:", + "CPU 0: hi: 186, btch: 31 usd: 86", + "active_anon:405991 inactive_anon:57 isolated_anon:0", + " active_file:35 inactive_file:69 isolated_file:0", + " unevictable:0 dirty:0 writeback:0 unstable:0", + " free:12929 slab_reclaimable:1635 slab_unreclaimable:1919", + " mapped:34 shmem:70 pagetables:1423 bounce:0", + " free_cma:0", + "Node 0 DMA free:7124kB min:412kB low:512kB high:616kB active_anon:8508kB inactive_anon:4kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:4kB slab_reclaimable:16kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:12kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes", + "lowmem_reserve[]: 0 1679 1679 1679", + "Node 0 DMA32 free:44592kB min:44640kB low:55800kB high:66960kB active_anon:1615456kB inactive_anon:224kB active_file:140kB inactive_file:276kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1765368kB managed:1722912kB mlocked:0kB dirty:0kB writeback:0kB mapped:136kB shmem:276kB slab_reclaimable:6524kB slab_unreclaimable:7660kB kernel_stack:592kB pagetables:5680kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:819 all_unreclaimable? yes", + "lowmem_reserve[]: 0 0 0 0", + "Node 0 DMA: 5*4kB (UM) 6*8kB (UEM) 7*16kB (UEM) 1*32kB (M) 2*64kB (UE) 3*128kB (UEM) 1*256kB (E) 2*512kB (EM) 3*1024kB (UEM) 1*2048kB (R) 0*4096kB = 7124kB", + "Node 0 DMA32: 74*4kB (UEM) 125*8kB (UEM) 78*16kB (UEM) 26*32kB (UE) 12*64kB (UEM) 4*128kB (UE) 4*256kB (UE) 2*512kB (E) 11*1024kB (UE) 7*2048kB (UE) 3*4096kB (UR) = 44592kB", + "Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB", + "204 total pagecache pages", + "0 pages in swap cache", + "Swap cache stats: add 0, delete 0, find 0/0", + "Free swap = 0kB", + "Total swap = 0kB", + "445340 pages RAM", + "0 pages HighMem/MovableOnly", + "10614 pages reserved", + "[ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name", + "[ 273] 0 273 4869 50 13 0 0 upstart-udev-br", + "[ 293] 0 293 12802 154 28 0 -1000 systemd-udevd", + "[ 321] 0 321 3819 54 12 0 0 upstart-file-br", + "[ 326] 102 326 9805 109 24 0 0 dbus-daemon", + "[ 334] 101 334 63960 94 26 0 0 rsyslogd", + "[ 343] 0 343 10863 102 26 0 0 systemd-logind", + "[ 546] 0 546 3815 60 13 0 0 upstart-socket-", + "[ 710] 0 710 2556 587 8 0 0 dhclient", + "[ 863] 0 863 3955 48 13 0 0 getty", + "[ 865] 0 865 3955 50 13 0 0 getty", + "[ 867] 0 867 3955 51 13 0 0 getty", + "[ 868] 0 868 3955 51 12 0 0 getty", + "[ 870] 0 870 3955 49 13 0 0 getty", + "[ 915] 0 915 5914 61 16 0 0 cron", + "[ 1015] 0 1015 10885 1524 25 0 0 manage_addresse", + "[ 1028] 0 1028 3955 49 13 0 0 getty", + "[ 1033] 0 1033 3197 48 12 0 0 getty", + "[ 1264] 0 1264 11031 1635 26 0 0 manage_accounts", + "[ 1268] 0 1268 15341 180 33 0 -1000 sshd", + "[ 1313] 104 1313 6804 154 17 0 0 ntpd", + "[ 1389] 0 1389 25889 255 55 0 0 sshd", + "[ 1407] 1020 1407 25889 255 52 0 0 sshd", + "[ 1408] 1020 1408 5711 581 17 0 0 bash", + "[ 1425] 0 1425 25889 256 53 0 0 sshd", + "[ 1443] 1020 1443 25889 257 52 0 0 sshd", + "[ 1444] 1020 1444 5711 581 16 0 0 bash", + "[ 1476] 1020 1476 1809 25 9 0 0 tail", + "[ 1532] 1020 1532 410347 398810 788 0 0 badsysprogram", + "Out of memory: Kill process 1532 (badsysprogram) score 919 or sacrifice child", + "Killed process 1532 (badsysprogram) total-vm:1641388kB, anon-rss:1595164kB, file-rss:76kB", + }, + }}, + out: []*OomInstance{{ + Pid: 1532, + ProcessName: "badsysprogram", + TimeOfDeath: testTime, + ContainerName: "/", + VictimContainerName: "", + }}, + }, + { // Multiple OOMs + // These were generated via `docker run -m 20M euank/gunpowder-memhog 2G; docker run -m 300M euank/gunpowder-memhog 800M` + // followed by nabbing output from `/dev/kmsg` and stripping the syslog-ish prefixes `kmsgparser` will handle anyways. + in: []in{ + { + time: testTime, + msgs: []string{ + "docker0: port 2(veth380a1cd) entered disabled state", + "device veth380a1cd left promiscuous mode", + "docker0: port 2(veth380a1cd) entered disabled state", + "docker0: port 2(vethcd0dbfb) entered blocking state", + "docker0: port 2(vethcd0dbfb) entered disabled state", + "device vethcd0dbfb entered promiscuous mode", + "IPv6: ADDRCONF(NETDEV_UP): vethcd0dbfb: link is not ready", + "IPv6: ADDRCONF(NETDEV_CHANGE): vethcd0dbfb: link becomes ready", + "docker0: port 2(vethcd0dbfb) entered blocking state", + "docker0: port 2(vethcd0dbfb) entered forwarding state", + "docker0: port 2(vethcd0dbfb) entered disabled state", + "eth0: renamed from vethbcd01c4", + "docker0: port 2(vethcd0dbfb) entered blocking state", + "docker0: port 2(vethcd0dbfb) entered forwarding state", + "gunpowder-memho invoked oom-killer: gfp_mask=0x24000c0(GFP_KERNEL), order=0, oom_score_adj=0", + "gunpowder-memho cpuset=2e088fe462e25e60be1dafafe2c05c47bda1a97978648d10ad2b7484fc0b8f50 mems_allowed=0", + "CPU: 0 PID: 1381 Comm: gunpowder-memho Tainted: G O 4.8.0-gentoo #2", + "Hardware name: LENOVO 20BSCTO1WW/20BSCTO1WW, BIOS N14ET32W (1.10 ) 08/13/2015", + " 0000000000000000 ffff8800968e3ca0 ffffffff8137ad47 ffff8800968e3d68", + " ffff8800b74ee540 ffff8800968e3d00 ffffffff811261dd 0000000000000003", + " 0000000000000000 0000000000000001 0000000000000246 0000000000000202", + "Call Trace:", + " [] dump_stack+0x4d/0x63", + " [] dump_header+0x58/0x1c8", + " [] oom_kill_process+0x7e/0x362", + " [] ? mem_cgroup_iter+0x109/0x23e", + " [] mem_cgroup_out_of_memory+0x241/0x299", + " [] mem_cgroup_oom_synchronize+0x273/0x28c", + " [] ? __mem_cgroup_insert_exceeded+0x76/0x76", + " [] pagefault_out_of_memory+0x1f/0x76", + " [] mm_fault_error+0x56/0x108", + " [] __do_page_fault+0x36b/0x3ee", + " [] do_page_fault+0xc/0xe", + " [] page_fault+0x22/0x30", + "Task in /docker/2e088fe462e25e60be1dafafe2c05c47bda1a97978648d10ad2b7484fc0b8f50 killed as a result of limit of /docker/2e088fe462e25e60be1dafafe2c05c47bda1a97978648d10ad2b7484fc0b8f50", + "memory: usage 20480kB, limit 20480kB, failcnt 1204", + "memory+swap: usage 40940kB, limit 40960kB, failcnt 6", + "kmem: usage 220kB, limit 9007199254740988kB, failcnt 0", + "Memory cgroup stats for /docker/2e088fe462e25e60be1dafafe2c05c47bda1a97978648d10ad2b7484fc0b8f50: cache:0KB rss:20260KB rss_huge:0KB mapped_file:0KB dirty:0KB writeback:1016KB swap:20460KB inactive_anon:10232KB active_anon:10028KB inactive_file:0KB active_file:0KB unevictable:0KB", + "[ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name", + "[ 1381] 0 1381 530382 5191 34 4 5489 0 gunpowder-memho", + "Memory cgroup out of memory: Kill process 1381 (gunpowder-memho) score 1046 or sacrifice child", + "Killed process 1381 (gunpowder-memho) total-vm:2121528kB, anon-rss:18624kB, file-rss:2140kB, shmem-rss:0kB", + "oom_reaper: reaped process 1381 (gunpowder-memho), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB", + "docker0: port 2(vethcd0dbfb) entered disabled state", + "vethbcd01c4: renamed from eth0", + "docker0: port 2(vethcd0dbfb) entered disabled state", + "device vethcd0dbfb left promiscuous mode", + "docker0: port 2(vethcd0dbfb) entered disabled state", + "docker0: port 2(veth4cb51e1) entered blocking state", + "docker0: port 2(veth4cb51e1) entered disabled state", + "device veth4cb51e1 entered promiscuous mode", + }, + }, + { + time: testTime2, + msgs: []string{ + "IPv6: ADDRCONF(NETDEV_UP): veth4cb51e1: link is not ready", + "docker0: port 2(veth4cb51e1) entered blocking state", + "docker0: port 2(veth4cb51e1) entered forwarding state", + "IPv6: ADDRCONF(NETDEV_CHANGE): veth4cb51e1: link becomes ready", + "docker0: port 2(veth4cb51e1) entered disabled state", + "eth0: renamed from veth4b89c12", + "docker0: port 2(veth4cb51e1) entered blocking state", + "docker0: port 2(veth4cb51e1) entered forwarding state", + "gunpowder-memho invoked oom-killer: gfp_mask=0x24000c0(GFP_KERNEL), order=0, oom_score_adj=0", + "gunpowder-memho cpuset=6c6fcab8562fd3150854986b78552c732f234fd405b624207b8843528a145e70 mems_allowed=0", + "CPU: 0 PID: 1667 Comm: gunpowder-memho Tainted: G O 4.8.0-gentoo #2", + "Hardware name: LENOVO 20BSCTO1WW/20BSCTO1WW, BIOS N14ET32W (1.10 ) 08/13/2015", + " 0000000000000000 ffff88008137fca0 ffffffff8137ad47 ffff88008137fd68", + " ffff8801c75b0c40 ffff88008137fd00 ffffffff811261dd 0000000000000003", + " 0000000000000000 0000000000000001 0000000000000246 0000000000000202", + "Call Trace:", + " [] dump_stack+0x4d/0x63", + " [] dump_header+0x58/0x1c8", + " [] oom_kill_process+0x7e/0x362", + " [] ? mem_cgroup_iter+0x109/0x23e", + " [] mem_cgroup_out_of_memory+0x241/0x299", + " [] mem_cgroup_oom_synchronize+0x273/0x28c", + " [] ? __mem_cgroup_insert_exceeded+0x76/0x76", + " [] pagefault_out_of_memory+0x1f/0x76", + " [] mm_fault_error+0x56/0x108", + " [] __do_page_fault+0x36b/0x3ee", + " [] do_page_fault+0xc/0xe", + " [] page_fault+0x22/0x30", + "Task in /docker/6c6fcab8562fd3150854986b78552c732f234fd405b624207b8843528a145e70 killed as a result of limit of /docker/6c6fcab8562fd3150854986b78552c732f234fd405b624207b8843528a145e70", + "memory: usage 307112kB, limit 307200kB, failcnt 35982", + "memory+swap: usage 614400kB, limit 614400kB, failcnt 11", + "kmem: usage 1308kB, limit 9007199254740988kB, failcnt 0", + "Memory cgroup stats for /docker/6c6fcab8562fd3150854986b78552c732f234fd405b624207b8843528a145e70: cache:0KB rss:305804KB rss_huge:0KB mapped_file:0KB dirty:0KB writeback:55884KB swap:307288KB inactive_anon:152940KB active_anon:152832KB inactive_file:0KB active_file:0KB unevictable:0KB", + "[ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name", + "[ 1667] 0 1667 210894 62557 315 4 91187 0 gunpowder-memho", + "Memory cgroup out of memory: Kill process 1667 (gunpowder-memho) score 1003 or sacrifice child", + "Killed process 1667 (gunpowder-memho) total-vm:843576kB, anon-rss:248180kB, file-rss:2048kB, shmem-rss:0kB", + "oom_reaper: reaped process 1667 (gunpowder-memho), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB", + "docker0: port 2(veth4cb51e1) entered disabled state", + "veth4b89c12: renamed from eth0", + "docker0: port 2(veth4cb51e1) entered blocking state", + "docker0: port 2(veth4cb51e1) entered forwarding state", + "docker0: port 2(veth4cb51e1) entered disabled state", + "device veth4cb51e1 left promiscuous mode", + "docker0: port 2(veth4cb51e1) entered disabled state", + }, + }, + }, + out: []*OomInstance{ + { + Pid: 1381, + ProcessName: "gunpowder-memho", + TimeOfDeath: testTime, + ContainerName: "/docker/2e088fe462e25e60be1dafafe2c05c47bda1a97978648d10ad2b7484fc0b8f50", + VictimContainerName: "/docker/2e088fe462e25e60be1dafafe2c05c47bda1a97978648d10ad2b7484fc0b8f50", + }, + { + Pid: 1667, + ProcessName: "gunpowder-memho", + TimeOfDeath: testTime2, + ContainerName: "/docker/6c6fcab8562fd3150854986b78552c732f234fd405b624207b8843528a145e70", + VictimContainerName: "/docker/6c6fcab8562fd3150854986b78552c732f234fd405b624207b8843528a145e70", + }, + }, + }, } - return &OomParser{ - ioreader: bufio.NewReader(file), + + for _, pair := range testPairs { + go func() { + for _, x := range pair.in { + writeAll(x.msgs, x.time) + } + }() + for _, expected := range pair.out { + oom := <-oomsOut + assert.Equal(t, expected, oom) + } + + select { + case oom := <-oomsOut: + t.Errorf("did not expect any remaining OOMs, got %+v", oom) + default: + } + } } + +type mockKmsgParser struct { + messages chan kmsgparser.Message +} + +func (m *mockKmsgParser) SeekEnd() error { + return nil +} + +func (m *mockKmsgParser) Parse() <-chan kmsgparser.Message { + return m.messages +} + +func (m *mockKmsgParser) SetLogger(kmsgparser.Logger) {} +func (m *mockKmsgParser) Close() error { + close(m.messages) + return nil +} diff --git a/utils/oomparser/systemOomExampleLog.txt b/utils/oomparser/systemOomExampleLog.txt deleted file mode 100644 index 9d38bbdee9..0000000000 --- a/utils/oomparser/systemOomExampleLog.txt +++ /dev/null @@ -1,362 +0,0 @@ -[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 -[ 0.000000] Hierarchical RCU implementation. -[ 0.000000] RCU dyntick-idle grace-period acceleration is enabled. -[ 0.000000] RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=1. -[ 0.000000] Offload RCU callbacks from all CPUs -[ 0.000000] Offload RCU callbacks from CPUs: 0. -[ 0.000000] NR_IRQS:16640 nr_irqs:256 16 -[ 0.000000] Console: colour dummy device 80x25 -[ 0.000000] console [ttyS0] enabled -[ 0.000000] allocated 7340032 bytes of page_cgroup -[ 0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups -[ 0.000000] tsc: Detected 2500.000 MHz processor -[ 0.008000] Calibrating delay loop (skipped) preset value.. 5000.00 BogoMIPS (lpj=10000000) -[ 0.008000] pid_max: default: 32768 minimum: 301 -[ 0.008000] Security Framework initialized -[ 0.008000] AppArmor: AppArmor initialized -[ 0.008000] Yama: becoming mindful. -[ 0.008200] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes) -[ 0.011365] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes) -[ 0.013066] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes) -[ 0.014030] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes) -[ 0.016266] Initializing cgroup subsys memory -[ 0.016898] Initializing cgroup subsys devices -[ 0.017546] Initializing cgroup subsys freezer -[ 0.018193] Initializing cgroup subsys blkio -[ 0.018793] Initializing cgroup subsys perf_event -[ 0.019416] Initializing cgroup subsys hugetlb -[ 0.020067] Disabled fast string operations -[ 0.020681] CPU: Physical Processor ID: 0 -[ 0.021238] CPU: Processor Core ID: 0 -[ 0.022587] mce: CPU supports 32 MCE banks -[ 0.023260] Last level iTLB entries: 4KB 512, 2MB 0, 4MB 0 -[ 0.023260] Last level dTLB entries: 4KB 512, 2MB 0, 4MB 0 -[ 0.023260] tlb_flushall_shift: 6 -[ 0.043758] Freeing SMP alternatives memory: 32K (ffffffff81e6c000 - ffffffff81e74000) -[ 0.048361] ACPI: Core revision 20131115 -[ 0.049516] ACPI: All ACPI Tables successfully acquired -[ 0.050342] ftrace: allocating 28458 entries in 112 pages -[ 0.060327] Enabling x2apic -[ 0.060740] Enabled x2apic -[ 0.064005] Switched APIC routing to physical x2apic. -[ 0.065489] ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1 -[ 0.066331] smpboot: CPU0: Intel(R) Xeon(R) CPU @ 2.50GHz (fam: 06, model: 3e, stepping: 04) -[ 0.072000] APIC calibration not consistent with PM-Timer: 227ms instead of 100ms -[ 0.072000] APIC delta adjusted to PM-Timer: 6250028 (14249259) -[ 0.074382] Performance Events: unsupported p6 CPU model 62 no PMU driver, software events only. -[ 0.077174] x86: Booted up 1 node, 1 CPUs -[ 0.077738] smpboot: Total of 1 processors activated (5000.00 BogoMIPS) -[ 0.078932] NMI watchdog: disabled (cpu0): hardware events not enabled -[ 0.079945] devtmpfs: initialized -[ 0.081784] EVM: security.selinux -[ 0.082251] EVM: security.SMACK64 -[ 0.082720] EVM: security.ima -[ 0.083135] EVM: security.capability -[ 0.084729] pinctrl core: initialized pinctrl subsystem -[ 0.085517] regulator-dummy: no parameters -[ 0.086187] RTC time: 19:51:09, date: 01/28/15 -[ 0.086869] NET: Registered protocol family 16 -[ 0.087613] cpuidle: using governor ladder -[ 0.088009] cpuidle: using governor menu -[ 0.088580] ACPI: bus type PCI registered -[ 0.089191] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 -[ 0.090220] PCI: Using configuration type 1 for base access -[ 0.091749] bio: create slab at 0 -[ 0.092215] ACPI: Added _OSI(Module Device) -[ 0.092799] ACPI: Added _OSI(Processor Device) -[ 0.093410] ACPI: Added _OSI(3.0 _SCP Extensions) -[ 0.094173] ACPI: Added _OSI(Processor Aggregator Device) -[ 0.096962] ACPI: Interpreter enabled -[ 0.097483] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S1_] (20131115/hwxface-580) -[ 0.098762] ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S2_] (20131115/hwxface-580) -[ 0.100011] ACPI: (supports S0 S3 S4 S5) -[ 0.100555] ACPI: Using IOAPIC for interrupt routing -[ 0.101252] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug -[ 0.102545] ACPI: No dock devices found. -[ 0.105210] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) -[ 0.106060] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI] -[ 0.108025] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM -[ 0.109116] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. -[ 0.112685] PCI host bridge to bus 0000:00 -[ 0.113294] pci_bus 0000:00: root bus resource [bus 00-ff] -[ 0.114054] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7] -[ 0.115065] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff] -[ 0.116004] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff] -[ 0.116955] pci_bus 0000:00: root bus resource [mem 0x6cc00000-0xfebfffff] -[ 0.117916] pci 0000:00:01.0: [8086:7110] type 00 class 0x060100 -[ 0.122089] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 -[ 0.125713] pci 0000:00:01.3: quirk: [io 0xb000-0xb03f] claimed by PIIX4 ACPI -[ 0.127117] pci 0000:00:03.0: [1af4:1004] type 00 class 0x000000 -[ 0.128752] pci 0000:00:03.0: reg 0x10: [io 0xc000-0xc03f] -[ 0.130322] pci 0000:00:03.0: reg 0x14: [mem 0xfebfe000-0xfebfe07f] -[ 0.133571] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 -[ 0.135267] pci 0000:00:04.0: reg 0x10: [io 0xc040-0xc07f] -[ 0.136777] pci 0000:00:04.0: reg 0x14: [mem 0xfebff000-0xfebff03f] -[ 0.140811] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11) -[ 0.141879] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11) -[ 0.142886] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11) -[ 0.144086] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11) -[ 0.145067] ACPI: PCI Interrupt Link [LNKS] (IRQs *9) -[ 0.146245] ACPI: Enabled 16 GPEs in block 00 to 0F -[ 0.147038] ACPI: \_SB_.PCI0: notify handler is installed -[ 0.147840] Found 1 acpi root devices -[ 0.148136] vgaarb: loaded -[ 0.148780] SCSI subsystem initialized -[ 0.149472] libata version 3.00 loaded. -[ 0.150070] ACPI: bus type USB registered -[ 0.150659] usbcore: registered new interface driver usbfs -[ 0.151536] usbcore: registered new interface driver hub -[ 0.152055] usbcore: registered new device driver usb -[ 0.153144] PCI: Using ACPI for IRQ routing -[ 0.153756] PCI: pci_cache_line_size set to 64 bytes -[ 0.154617] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff] -[ 0.156004] e820: reserve RAM buffer [mem 0x6cbfe000-0x6fffffff] -[ 0.156993] NetLabel: Initializing -[ 0.157498] NetLabel: domain hash size = 128 -[ 0.158082] NetLabel: protocols = UNLABELED CIPSOv4 -[ 0.158815] NetLabel: unlabeled traffic allowed by default -[ 0.160005] Switched to clocksource kvm-clock -[ 0.168695] AppArmor: AppArmor Filesystem Enabled -[ 0.169361] pnp: PnP ACPI init -[ 0.169853] ACPI: bus type PNP registered -[ 0.170499] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active) -[ 0.171591] pnp 00:01: Plug and Play ACPI device, IDs PNP0501 (active) -[ 0.172574] pnp 00:02: Plug and Play ACPI device, IDs PNP0501 (active) -[ 0.173782] pnp: PnP ACPI: found 3 devices -[ 0.174430] ACPI: bus type PNP unregistered -[ 0.181364] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7] -[ 0.182172] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff] -[ 0.183049] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff] -[ 0.184120] pci_bus 0000:00: resource 7 [mem 0x6cc00000-0xfebfffff] -[ 0.185051] NET: Registered protocol family 2 -[ 0.185859] TCP established hash table entries: 16384 (order: 5, 131072 bytes) -[ 0.187117] TCP bind hash table entries: 16384 (order: 6, 262144 bytes) -[ 0.188393] TCP: Hash tables configured (established 16384 bind 16384) -[ 0.189429] TCP: reno registered -[ 0.189929] UDP hash table entries: 1024 (order: 3, 32768 bytes) -[ 0.190824] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes) -[ 0.191830] NET: Registered protocol family 1 -[ 0.192585] PCI: CLS 0 bytes, default 64 -[ 0.193412] Trying to unpack rootfs image as initramfs... -[ 0.897565] Freeing initrd memory: 18780K (ffff880035b42000 - ffff880036d99000) -[ 0.898982] microcode: CPU0 sig=0x306e4, pf=0x1, revision=0x1 -[ 0.899884] microcode: Microcode Update Driver: v2.00 , Peter Oruba -[ 0.901196] Scanning for low memory corruption every 60 seconds -[ 0.902497] Initialise system trusted keyring -[ 0.903169] audit: initializing netlink socket (disabled) -[ 0.904016] type=2000 audit(1422474669.702:1): initialized -[ 0.926617] HugeTLB registered 2 MB page size, pre-allocated 0 pages -[ 0.928567] zbud: loaded -[ 0.929030] VFS: Disk quotas dquot_6.5.2 -[ 0.929685] Dquot-cache hash table entries: 512 (order 0, 4096 bytes) -[ 0.931113] fuse init (API version 7.22) -[ 0.931781] msgmni has been set to 3390 -[ 0.932595] Key type big_key registered -[ 0.933680] Key type asymmetric registered -[ 0.934332] Asymmetric key parser 'x509' registered -[ 0.935078] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252) -[ 0.936224] io scheduler noop registered -[ 0.936858] io scheduler deadline registered (default) -[ 0.937675] io scheduler cfq registered -[ 0.938307] pci_hotplug: PCI Hot Plug PCI Core version: 0.5 -[ 0.939158] pciehp: PCI Express Hot Plug Controller Driver version: 0.4 -[ 0.940239] efifb: probing for efifb -[ 0.940788] efifb: framebuffer at 0xa0000, mapped to 0xffff8800000a0000, using 64k, total 64k -[ 0.942044] efifb: mode is 640x480x1, linelength=80, pages=1 -[ 0.942964] efifb: scrolling: redraw -[ 0.943525] efifb: Truecolor: size=8:8:8:8, shift=24:16:8:0 -[ 0.945209] Console: switching to colour frame buffer device 80x30 -[ 0.946826] fb0: EFI VGA frame buffer device -[ 0.947485] intel_idle: does not run on family 6 model 62 -[ 0.948380] ipmi message handler version 39.2 -[ 0.949036] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 -[ 0.950135] ACPI: Power Button [PWRF] -[ 0.950722] input: Sleep Button as /devices/LNXSYSTM:00/LNXSLPBN:00/input/input1 -[ 0.951773] ACPI: Sleep Button [SLPF] -[ 0.952529] GHES: HEST is not enabled! -[ 0.953921] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11 -[ 0.955783] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10 -[ 0.957395] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled -[ 1.112167] 00:01: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A -[ 1.134843] 00:02: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A -[ 1.137110] Linux agpgart interface v0.103 -[ 1.138975] brd: module loaded -[ 1.140117] loop: module loaded -[ 1.140923] libphy: Fixed MDIO Bus: probed -[ 1.141640] tun: Universal TUN/TAP device driver, 1.6 -[ 1.142342] tun: (C) 1999-2004 Max Krasnyansky -[ 1.144063] virtio-pci 0000:00:04.0: irq 40 for MSI/MSI-X -[ 1.144871] virtio-pci 0000:00:04.0: irq 41 for MSI/MSI-X -[ 1.145670] virtio-pci 0000:00:04.0: irq 42 for MSI/MSI-X -[ 1.151673] PPP generic driver version 2.4.2 -[ 1.152344] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver -[ 1.153399] ehci-pci: EHCI PCI platform driver -[ 1.154021] ehci-platform: EHCI generic platform driver -[ 1.154939] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver -[ 1.155973] ohci-pci: OHCI PCI platform driver -[ 1.156675] ohci-platform: OHCI generic platform driver -[ 1.157423] uhci_hcd: USB Universal Host Controller Interface driver -[ 1.158352] i8042: PNP: No PS/2 controller found. Probing ports directly. -[ 3.646820] i8042: No controller found -[ 3.647493] tsc: Refined TSC clocksource calibration: 2500.002 MHz -[ 3.648490] mousedev: PS/2 mouse device common for all mice -[ 3.649499] rtc_cmos 00:00: RTC can wake from S4 -[ 3.650595] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0 -[ 3.651521] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram -[ 3.652422] device-mapper: uevent: version 1.0.3 -[ 3.653131] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@redhat.com -[ 3.654281] ledtrig-cpu: registered to indicate activity on CPUs -[ 3.655182] TCP: cubic registered -[ 3.655704] NET: Registered protocol family 10 -[ 3.656551] NET: Registered protocol family 17 -[ 3.657183] Key type dns_resolver registered -[ 3.657931] Loading compiled-in X.509 certificates -[ 3.659264] Loaded X.509 cert 'Magrathea: Glacier signing key: 23984ac203784325ccf7b95b51f6c119380eb933' -[ 3.660726] registered taskstats version 1 -[ 3.663211] Key type trusted registered -[ 3.665462] Key type encrypted registered -[ 3.667679] AppArmor: AppArmor sha1 policy hashing enabled -[ 3.668454] IMA: No TPM chip found, activating TPM-bypass! -[ 3.669388] regulator-dummy: disabling -[ 3.669971] Magic number: 15:428:901 -[ 3.670625] clocksource clocksource0: hash matches -[ 3.671311] acpi PNP0501:01: hash matches -[ 3.671953] rtc_cmos 00:00: setting system clock to 2015-01-28 19:51:13 UTC (1422474673) -[ 3.673268] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found -[ 3.674088] EDD information not available. -[ 3.674668] PM: Hibernation image not present or could not be loaded. -[ 3.676577] Freeing unused kernel memory: 1332K (ffffffff81d1f000 - ffffffff81e6c000) -[ 3.678370] Write protecting the kernel read-only data: 12288k -[ 3.681251] Freeing unused kernel memory: 828K (ffff880001731000 - ffff880001800000) -[ 3.684444] Freeing unused kernel memory: 700K (ffff880001b51000 - ffff880001c00000) -[ 3.700162] systemd-udevd[90]: starting version 204 -[ 3.866262] virtio-pci 0000:00:03.0: irq 43 for MSI/MSI-X -[ 3.867187] virtio-pci 0000:00:03.0: irq 44 for MSI/MSI-X -[ 3.867997] virtio-pci 0000:00:03.0: irq 45 for MSI/MSI-X -[ 3.876214] virtio-pci 0000:00:03.0: irq 46 for MSI/MSI-X -[ 3.880005] scsi0 : Virtio SCSI HBA -[ 3.912410] scsi 0:0:1:0: Direct-Access Google PersistentDisk 1 PQ: 0 ANSI: 6 -[ 3.938957] sd 0:0:1:0: Attached scsi generic sg0 type 0 -[ 3.939845] sd 0:0:1:0: [sda] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB) -[ 3.941149] sd 0:0:1:0: [sda] 4096-byte physical blocks -[ 3.942233] sd 0:0:1:0: [sda] Write Protect is off -[ 3.942988] sd 0:0:1:0: [sda] Mode Sense: 1f 00 00 08 -[ 3.944398] sd 0:0:1:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA -[ 3.961885] sda: sda1 -[ 3.963152] sd 0:0:1:0: [sda] Attached SCSI disk -[ 4.414649] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null) -[ 5.293574] random: init urandom read with 73 bits of entropy available -[ 6.418187] random: nonblocking pool is initialized -[ 6.692508] EXT4-fs (sda1): re-mounted. Opts: errors=remount-ro -[ 7.121847] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready -[ 7.681714] systemd-udevd[293]: starting version 204 -[ 8.437234] lp: driver loaded but no devices found -[ 9.164195] piix4_smbus 0000:00:01.3: SMBus base address uninitialized - upgrade BIOS or use force_addr=0xaddr -[ 9.648096] device-mapper: multipath: version 1.6.0 loaded -[ 10.434575] type=1400 audit(1422474680.256:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/sbin/dhclient" pid=368 comm="apparmor_parser" -[ 10.437242] type=1400 audit(1422474680.260:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=368 comm="apparmor_parser" -[ 10.439901] type=1400 audit(1422474680.260:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=368 comm="apparmor_parser" -[ 11.126295] type=1400 audit(1422474680.948:5): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/sbin/dhclient" pid=412 comm="apparmor_parser" -[ 11.129123] type=1400 audit(1422474680.952:6): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=412 comm="apparmor_parser" -[ 11.132139] type=1400 audit(1422474680.956:7): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=412 comm="apparmor_parser" -[ 11.196173] type=1400 audit(1422474681.020:8): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/sbin/dhclient" pid=458 comm="apparmor_parser" -[ 11.198887] type=1400 audit(1422474681.020:9): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=458 comm="apparmor_parser" -[ 11.201484] type=1400 audit(1422474681.028:10): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=458 comm="apparmor_parser" -[ 11.361371] init: udev-fallback-graphics main process (454) terminated with status 1 -[ 11.378437] type=1400 audit(1422474681.200:11): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=458 comm="apparmor_parser" -[ 14.366411] init: failsafe main process (491) killed by TERM signal -kateknister@kateknister-test3:~$ tail -f /var/log/syslog -Jan 28 19:51:47 localhost ntpdate[1240]: adjust time server 169.254.169.254 offset -0.383723 sec -Jan 28 19:51:47 localhost ntpd[1312]: ntpd 4.2.6p5@1.2349-o Wed Oct 9 19:08:06 UTC 2013 (1) -Jan 28 19:51:47 localhost ntpd[1313]: proto: precision = 0.449 usec -Jan 28 19:51:47 localhost ntpd[1313]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16 -Jan 28 19:51:47 localhost ntpd[1313]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123 -Jan 28 19:51:47 localhost ntpd[1313]: Listen and drop on 1 v6wildcard :: UDP 123 -Jan 28 19:51:47 localhost ntpd[1313]: Listen normally on 2 lo 127.0.0.1 UDP 123 -Jan 28 19:51:47 localhost ntpd[1313]: Listen normally on 3 eth0 10.240.192.196 UDP 123 -Jan 28 19:51:47 localhost ntpd[1313]: peers refreshed -Jan 28 19:51:47 localhost ntpd[1313]: Listening on routing socket on fd #20 for interface updates -Jan 28 19:58:45 localhost kernel: [ 455.498827] badsysprogram invoked oom-killer: gfp_mask=0x280da, order=0, oom_score_adj=0 -Jan 28 19:58:45 localhost kernel: [ 455.500173] badsysprogram cpuset=/ mems_allowed=0 -Jan 28 19:58:45 localhost kernel: [ 455.501007] CPU: 0 PID: 1532 Comm: badsysprogram Not tainted 3.13.0-27-generic #50-Ubuntu -Jan 28 19:58:45 localhost kernel: [ 455.502301] Hardware name: Google Google, BIOS Google 01/01/2011 -Jan 28 19:58:45 localhost kernel: [ 455.503298] 0000000000000000 ffff880069715a90 ffffffff817199c4 ffff8800680d8000 -Jan 28 19:58:45 localhost kernel: [ 455.504563] ffff880069715b18 ffffffff817142ff 0000000000000000 0000000000000000 -Jan 28 19:58:45 localhost kernel: [ 455.505779] 0000000000000000 0000000000000000 0000000000000000 0000000000000000 -Jan 28 19:58:45 localhost kernel: [ 455.506971] Call Trace: -Jan 28 19:58:45 localhost kernel: [ 455.507353] [] dump_stack+0x45/0x56 -Jan 28 19:58:45 localhost kernel: [ 455.508289] [] dump_header+0x7f/0x1f1 -Jan 28 19:58:45 localhost kernel: [ 455.509112] [] oom_kill_process+0x1ce/0x330 -Jan 28 19:58:45 localhost kernel: [ 455.510023] [] ? security_capable_noaudit+0x15/0x20 -Jan 28 19:58:45 localhost kernel: [ 455.510994] [] out_of_memory+0x414/0x450 -Jan 28 19:58:45 localhost kernel: [ 455.511820] [] __alloc_pages_nodemask+0xa87/0xb20 -Jan 28 19:58:45 localhost kernel: [ 455.512815] [] alloc_pages_vma+0x9a/0x140 -Jan 28 19:58:45 localhost kernel: [ 455.513647] [] handle_mm_fault+0xb2b/0xf10 -Jan 28 19:58:45 localhost kernel: [ 455.514498] [] __do_page_fault+0x184/0x560 -Jan 28 19:58:45 localhost kernel: [ 455.515415] [] ? sched_clock+0x9/0x10 -Jan 28 19:58:45 localhost kernel: [ 455.516318] [] ? sched_clock_local+0x1d/0x80 -Jan 28 19:58:45 localhost kernel: [ 455.517242] [] ? acct_account_cputime+0x1c/0x20 -Jan 28 19:58:45 localhost kernel: [ 455.518141] [] ? account_user_time+0x8b/0xa0 -Jan 28 19:58:45 localhost kernel: [ 455.519014] [] ? vtime_account_user+0x54/0x60 -Jan 28 19:58:45 localhost kernel: [ 455.519910] [] do_page_fault+0x1a/0x70 -Jan 28 19:58:45 localhost kernel: [ 455.520712] [] page_fault+0x28/0x30 -Jan 28 19:58:45 localhost kernel: [ 455.521498] Mem-Info: -Jan 28 19:58:45 localhost kernel: [ 455.521873] Node 0 DMA per-cpu: -Jan 28 19:58:45 localhost kernel: [ 455.522388] CPU 0: hi: 0, btch: 1 usd: 0 -Jan 28 19:58:45 localhost kernel: [ 455.598342] Node 0 DMA32 per-cpu: -Jan 28 19:58:45 localhost kernel: [ 455.598890] CPU 0: hi: 186, btch: 31 usd: 86 -Jan 28 19:58:45 localhost kernel: [ 455.599687] active_anon:405991 inactive_anon:57 isolated_anon:0 -Jan 28 19:58:45 localhost kernel: [ 455.599687] active_file:35 inactive_file:69 isolated_file:0 -Jan 28 19:58:45 localhost kernel: [ 455.599687] unevictable:0 dirty:0 writeback:0 unstable:0 -Jan 28 19:58:45 localhost kernel: [ 455.599687] free:12929 slab_reclaimable:1635 slab_unreclaimable:1919 -Jan 28 19:58:45 localhost kernel: [ 455.599687] mapped:34 shmem:70 pagetables:1423 bounce:0 -Jan 28 19:58:45 localhost kernel: [ 455.599687] free_cma:0 -Jan 28 19:58:45 localhost kernel: [ 455.604585] Node 0 DMA free:7124kB min:412kB low:512kB high:616kB active_anon:8508kB inactive_anon:4kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:4kB slab_reclaimable:16kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:12kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes -Jan 28 19:58:45 localhost kernel: [ 455.610811] lowmem_reserve[]: 0 1679 1679 1679 -Jan 28 19:58:45 localhost kernel: [ 455.611600] Node 0 DMA32 free:44592kB min:44640kB low:55800kB high:66960kB active_anon:1615456kB inactive_anon:224kB active_file:140kB inactive_file:276kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1765368kB managed:1722912kB mlocked:0kB dirty:0kB writeback:0kB mapped:136kB shmem:276kB slab_reclaimable:6524kB slab_unreclaimable:7660kB kernel_stack:592kB pagetables:5680kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:819 all_unreclaimable? yes -Jan 28 19:58:45 localhost kernel: [ 455.618372] lowmem_reserve[]: 0 0 0 0 -Jan 28 19:58:45 localhost kernel: [ 455.619041] Node 0 DMA: 5*4kB (UM) 6*8kB (UEM) 7*16kB (UEM) 1*32kB (M) 2*64kB (UE) 3*128kB (UEM) 1*256kB (E) 2*512kB (EM) 3*1024kB (UEM) 1*2048kB (R) 0*4096kB = 7124kB -Jan 28 19:58:45 localhost kernel: [ 455.621861] Node 0 DMA32: 74*4kB (UEM) 125*8kB (UEM) 78*16kB (UEM) 26*32kB (UE) 12*64kB (UEM) 4*128kB (UE) 4*256kB (UE) 2*512kB (E) 11*1024kB (UE) 7*2048kB (UE) 3*4096kB (UR) = 44592kB -Jan 28 19:58:45 localhost kernel: [ 455.625174] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB -Jan 28 19:58:45 localhost kernel: [ 455.626394] 204 total pagecache pages -Jan 28 19:58:45 localhost kernel: [ 455.626954] 0 pages in swap cache -Jan 28 19:58:45 localhost kernel: [ 455.627455] Swap cache stats: add 0, delete 0, find 0/0 -Jan 28 19:58:45 localhost kernel: [ 455.628242] Free swap = 0kB -Jan 28 19:58:45 localhost kernel: [ 455.628686] Total swap = 0kB -Jan 28 19:58:45 localhost kernel: [ 455.629147] 445340 pages RAM -Jan 28 19:58:45 localhost kernel: [ 455.629577] 0 pages HighMem/MovableOnly -Jan 28 19:58:45 localhost kernel: [ 455.630301] 10614 pages reserved -Jan 28 19:58:45 localhost kernel: [ 455.630787] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name -Jan 28 19:58:45 localhost kernel: [ 455.631937] [ 273] 0 273 4869 50 13 0 0 upstart-udev-br -Jan 28 19:58:45 localhost kernel: [ 455.633290] [ 293] 0 293 12802 154 28 0 -1000 systemd-udevd -Jan 28 19:58:45 localhost kernel: [ 455.634671] [ 321] 0 321 3819 54 12 0 0 upstart-file-br -Jan 28 19:58:45 localhost kernel: [ 455.636070] [ 326] 102 326 9805 109 24 0 0 dbus-daemon -Jan 28 19:58:45 localhost kernel: [ 455.637373] [ 334] 101 334 63960 94 26 0 0 rsyslogd -Jan 28 19:58:45 localhost kernel: [ 455.638761] [ 343] 0 343 10863 102 26 0 0 systemd-logind -Jan 28 19:58:45 localhost kernel: [ 455.640158] [ 546] 0 546 3815 60 13 0 0 upstart-socket- -Jan 28 19:58:45 localhost kernel: [ 455.641534] [ 710] 0 710 2556 587 8 0 0 dhclient -Jan 28 19:58:45 localhost kernel: [ 455.642834] [ 863] 0 863 3955 48 13 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.644139] [ 865] 0 865 3955 50 13 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.645325] [ 867] 0 867 3955 51 13 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.646621] [ 868] 0 868 3955 51 12 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.647963] [ 870] 0 870 3955 49 13 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.649234] [ 915] 0 915 5914 61 16 0 0 cron -Jan 28 19:58:45 localhost kernel: [ 455.650439] [ 1015] 0 1015 10885 1524 25 0 0 manage_addresse -Jan 28 19:58:45 localhost kernel: [ 455.651817] [ 1028] 0 1028 3955 49 13 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.653091] [ 1033] 0 1033 3197 48 12 0 0 getty -Jan 28 19:58:45 localhost kernel: [ 455.654783] [ 1264] 0 1264 11031 1635 26 0 0 manage_accounts -Jan 28 19:58:45 localhost kernel: [ 455.656657] [ 1268] 0 1268 15341 180 33 0 -1000 sshd -Jan 28 19:58:45 localhost kernel: [ 455.657865] [ 1313] 104 1313 6804 154 17 0 0 ntpd -Jan 28 19:58:45 localhost kernel: [ 455.659085] [ 1389] 0 1389 25889 255 55 0 0 sshd -Jan 28 19:58:45 localhost kernel: [ 455.660440] [ 1407] 1020 1407 25889 255 52 0 0 sshd -Jan 28 19:58:45 localhost kernel: [ 455.661595] [ 1408] 1020 1408 5711 581 17 0 0 bash -Jan 28 19:58:45 localhost kernel: [ 455.662887] [ 1425] 0 1425 25889 256 53 0 0 sshd -Jan 28 19:58:45 localhost kernel: [ 455.664075] [ 1443] 1020 1443 25889 257 52 0 0 sshd -Jan 28 19:58:45 localhost kernel: [ 455.665330] [ 1444] 1020 1444 5711 581 16 0 0 bash -Jan 28 19:58:45 localhost kernel: [ 455.666450] [ 1476] 1020 1476 1809 25 9 0 0 tail -Jan 28 19:58:45 localhost kernel: [ 455.667682] [ 1532] 1020 1532 410347 398810 788 0 0 badsysprogram -Jan 28 19:58:45 localhost kernel: [ 455.669006] Out of memory: Kill process 1532 (badsysprogram) score 919 or sacrifice child -Jan 28 19:58:45 localhost kernel: [ 455.670291] Killed process 1532 (badsysprogram) total-vm:1641388kB, anon-rss:1595164kB, file-rss:76kB -[ 0.170499] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active) -[ 0.171591] pnp 00:01: Plug and Play ACPI device, IDs PNP0501 (active) -[ 0.172574] pnp 00:02: Plug and Play ACPI device, IDs PNP0501 (active)