#!/usr/bin/python # -*- coding: utf-8 -*- # This file is part of Cockpit. # # Copyright (C) 2013 Red Hat, Inc. # # Cockpit is free software; you can redistribute it and/or modify it # under the terms of the GNU Lesser General Public License as published by # the Free Software Foundation; either version 2.1 of the License, or # (at your option) any later version. # # Cockpit is distributed in the hope that it will be useful, but # WITHOUT ANY WARRANTY; without even the implied warranty of # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU # Lesser General Public License for more details. # # You should have received a copy of the GNU Lesser General Public License # along with Cockpit; If not, see . import parent from testlib import * class TestJournal(MachineCase): def setUp(self): # we need a static ip for this test MachineCase.setUp(self, macaddr='52:54:00:9e:00:F4') def testBasic(self): b = self.browser b.wait_timeout(120) m = self.machine self.allow_restart_journal_messages() self.allow_journal_messages(".*Failed to get realtime timestamp: Cannot assign requested address.*") def inject_extras(): b.eval_js(""" ph_get_log_lines = function () { var lines = [ ], i; $('.cockpit-log-panel').children().each(function (i, e) { var $e = $(e); if ($e.is('.panel-heading')) { lines.push ($e.text()); } else { var msg = $e.find('.cockpit-log-message').text(); var ident = ''; var count = ''; if ($e.find('.cockpit-log-service-container').length > 0) { ident = $e.find('.cockpit-log-service-reduced').text(); // we need to slice the whitespace count = $e.find('.badge').text().slice(0, -1); } else { ident = $e.find('.cockpit-log-service').text(); } lines.push ([ ident, msg, count ]); } }); var journal_start_text = $('.journal-start').text(); if (journal_start_text !== "") lines.push(journal_start_text); // console.log(JSON.stringify(lines)); return lines; } """) # Certain versions of journald wont set _SYSTEMD_UNIT # correctly for entries that are processed after the # originating process has already exited. So we keep the # process around for a bit longer after the last line has been # output. # m.write("/etc/systemd/system/log123.service", """ [Unit] Description=123 different log lines [Service] ExecStart=/bin/sh -c '/usr/bin/seq 123; sleep 10' """) m.write("/etc/systemd/system/slow10.service", """ [Unit] Description=Slowly log 10 identical lines [Service] ExecStart=/bin/sh -c 'for s in $(seq 10); do echo SLOW; sleep 0.1; done; sleep 10' """) # Stop NTP and Chronyd if they are running. Timedatectl isn't # necessarily aware of them. # # HACK - https://bugzilla.redhat.com/show_bug.cgi?id=1352905 # m.execute("! systemctl --quiet is-active ntp || (systemctl disable ntp && systemctl stop ntp)") m.execute("! systemctl --quiet is-active chronyd || (systemctl disable chronyd && systemctl stop chronyd)") m.execute("timedatectl set-ntp off; timedatectl set-time 2038-01-01") self.login_and_go("/system/logs") inject_extras() b.eval_js(""" localTime = function(time) { var month_names = [ 'January', 'February', 'March', 'April', 'May', 'June', 'July', 'August', 'September', 'October', 'November', 'December' ]; var d = new Date(time); return month_names[d.getMonth()] + ' ' + d.getDate().toFixed() + ', ' + d.getFullYear().toFixed(); } """) # January 1, 2038 00:00:00Z in browser time expected_date = b.eval_js("localTime(2145916800000)") def wait_log_lines(expected): b.wait_js_func("""(function (expected) { var lines = ph_get_log_lines (); if (expected.length != lines.length) return false; for (i = 0; i < expected.length; i++) if (JSON.stringify(expected[i]) != JSON.stringify(lines[i])) return false; return true; })""", expected) def wait_journal_empty(): wait_log_lines([ ]) b.go("#/?prio=*&service=log123.service") wait_journal_empty() def wait_log123(): b.wait_js_func ("""(function () { var lines = ph_get_log_lines(); if (lines[0] != "%s") return false; var seq = 123; var seen_day = false; for (i = 1; i < lines.length; i++) { l = lines[i]; if (l[2] != "") { // console.log("repeat", l[2], "?"); return false; } if (l[0] == "systemd: ") { // console.log(l[1], "?"); return false; } else if (l[0] == "sh") { if (l[1] != seq.toString()) { // console.log(l[1], "?"); return false; } seq = seq - 1; } else { // console.log(l[0], "?"); return false; } } if (seq != 0) { // console.log("Didn't see all 'seq' lines.") return false; } return true; })""" % expected_date) m.execute("systemctl start log123") wait_log123() b.go("#/?prio=*&start=oldest&service=nonexisting.service") wait_journal_empty() b.go("#/?prio=*&start=oldest&service=log123.service") wait_log123() b.go("#/?prio=*&start=recent&service=nonexisting.service") wait_journal_empty() b.go("#/?prio=*&start=recent&service=log123.service") wait_log123() b.go("#/?prio=*&start=recent&service=slow10.service") wait_journal_empty() def wait_slow10(): wait_log_lines([ expected_date, [ "sh", "SLOW", "10" ] ]) m.execute("systemctl start slow10") wait_slow10() b.go("#/?prio=*&start=oldest&service=nonexisting.service") wait_journal_empty() b.go("#/?prio=*&start=oldest&service=slow10.service") wait_slow10() # Debian 8 doesn't have persistent journal logging across boots if m.image in [ "debian-stable" ]: return # insert messages as errors because we know these will be shown by default m.execute("systemctl start systemd-journald.service") m.execute("logger -p user.err --tag check-journal BEFORE BOOT"); b.go("#/?tag=check-journal") wait_log_lines([ expected_date, [ "check-journal", "BEFORE BOOT", "" ] ]) m.execute("systemctl stop systemd-journald.service") # Now reboot things m.spawn("sync && sync && sync && sleep 0.1 && reboot", "reboot") m.wait_reboot() m.execute("logger -p user.err --tag check-journal AFTER BOOT"); m.start_cockpit() b.switch_to_top() b.relogin('/system/logs') inject_extras() b.go("#/?tag=check-journal") wait_log_lines([ expected_date, [ "check-journal", "AFTER BOOT", "" ], [ "", "Reboot", "" ], [ "check-journal", "BEFORE BOOT", "" ] ]) b.go("#/?start=boot&tag=check-journal") wait_log_lines([ expected_date, [ "check-journal", "AFTER BOOT", "" ], "Load earlier entries", ]) b.click('#journal-load-earlier') wait_log_lines([ expected_date, [ "check-journal", "AFTER BOOT", "2" ], [ "", "Reboot", "" ], [ "check-journal", "BEFORE BOOT", "" ] ]) def testBinary(self): b = self.browser m = self.machine m.execute( """ python -c ' import socket s = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) s.connect("/run/systemd/journal/socket") s.send("MESSAGE=Hello \\01 World\\nPRIORITY=3\\nFOO=bar\\nBIN=a\\01b\\02c\\03\\n")' """) self.login_and_go("/system/logs") sel = "#journal-box .cockpit-logline .cockpit-log-message:contains('[13 bytes of binary data]')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) b.wait_text("#journal-entry-message", "[13 bytes of binary data]") def wait_field(name, value): row_sel = "#journal-entry-fields tr:contains('" + name + "')" b.wait_present(row_sel + " td:nth-child(2):contains('" + value + "')") wait_field("FOO", "bar") wait_field("BIN", "[6 bytes of binary data]") def testNoMessage(self): b = self.browser m = self.machine m.execute( """ python -c ' import socket s = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) s.connect("/run/systemd/journal/socket") s.send("PRIORITY=3\\nFOO=bar\\n")' """) self.login_and_go("/system/logs") sel = "#journal-box .cockpit-logline .cockpit-log-message:contains('[no data]')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) b.wait_text("#journal-entry-message", "[no data]") @skipImage("Newer version of ABRT required", "centos-7", "rhel-7", "fedora-25", "fedora-i386", "fedora-testing", "rhel-7-4") @skipImage("ABRT not available", "debian-stable", "debian-testing", "ubuntu-stable", "ubuntu-1604", "rhel-atomic", "fedora-atomic") def testAbrtSegv(self): b = self.browser m = self.machine self.login_and_go("/system/logs") m.execute("setenforce 0; ulimit -c unlimited; python -c 'import os; os.kill(os.getpid(), 11)' || true") sel = "#journal-box .cockpit-logline .cockpit-log-message:contains('crashed in posix_kill')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) def wait_field(name, value): row_sel = "#journal-entry-fields tr:contains('" + name + "')" b.wait_present(row_sel + " td:nth-child(2):contains('" + value + "')") wait_field("SYSLOG_IDENTIFIER", "abrt-notification") b.click("li:contains(Problem info)") wait_field("crash_function", "posix_kill") b.click("li:contains(Problem details)") sel = "#journal-entry-fields #accordion-markup .panel .panel-heading" sel += " .panel-title .accordion-toggle:contains('core_backtrace')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) sel = "#journal-entry #accordion-markup .panel .panel-collapse" sel += " .panel-body:contains('signal: 11 executable: ')" b.wait_present(sel) @skipImage("Newer version of ABRT required", "centos-7", "rhel-7", "fedora-25", "fedora-i386", "fedora-testing", "rhel-7-4") @skipImage("ABRT not available", "debian-stable", "debian-testing", "ubuntu-stable", "ubuntu-1604", "rhel-atomic", "fedora-atomic") def testAbrtDelete(self): b = self.browser m = self.machine self.login_and_go("/system/logs") m.execute("setenforce 0; ulimit -c unlimited; echo 'sleep 42m &' > slp; chmod u+x slp") m.execute("./slp; killall -s SIGSEGV sleep") sel = "#journal-box .cockpit-logline .cockpit-log-message:contains('crashed in __nanosleep()')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) sel = "#journal-entry-fields .nav .btn-danger" b.wait_present(sel) b.wait_visible(sel) b.click(sel) b.wait_visible("#journal-box") b.wait_in_text('#journal-box', "__nanosleep") sel = "#journal-box .cockpit-logline .cockpit-log-message:contains('crashed in __nanosleep()')" b.click(sel) b.wait_present('.cockpit-log-panel') b.wait_visible('.cockpit-log-panel') sel = "#journal-entry .panel #journal-entry-message:contains('crashed in __nanosleep()')" b.wait_present(sel) @skipImage("Newer version of ABRT required", "centos-7", "rhel-7", "fedora-25", "fedora-i386", "fedora-testing", "rhel-7-4") @skipImage("ABRT not available", "debian-stable", "debian-testing", "ubuntu-stable", "ubuntu-1604", "rhel-atomic", "fedora-atomic") def testAbrtReport(self): b = self.browser m = self.machine self.login_and_go("/system/logs") m.execute("setenforce 0; ulimit -c unlimited; echo 'sleep 42m &' > slp; chmod u+x slp") m.execute("./slp; killall -s SIGSEGV sleep") sel = "#journal-box .cockpit-logline .cockpit-log-message:contains('crashed in __nanosleep()')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) # Wait until loaded (when delete button is loaded, all is loaded) sel = "#journal-entry-fields .nav .btn-danger" b.wait_present(sel) b.wait_visible(sel) # If 'Reported' then skip test sel = "#journal-entry-fields .nav .problem-btn:contains('Reported')" if b.is_present(sel): return sel = "#journal-entry-fields .nav .btn-primary:contains('Report')" b.wait_present(sel) b.wait_visible(sel) b.click(sel) sel = "#journal-entry-fields .nav .problem-btn:contains('Reported')" b.wait_present(sel) b.wait_visible(sel) self.assertTrue("/reports/bthash/" in b.attr(sel, 'href')) if __name__ == '__main__': test_main()