action #43055
closed[functional][y] test fails in kate - excessive systemd debug level?
0%
Description
Observation¶
openQA test in scenario opensuse-Tumbleweed-DVD-x86_64-kde@64bit fails in
kate
kate.journal:¶
Oct 29 09:58:03 susetest systemd[1]: Received SIGCHLD from PID 13216 (snapperd).
Oct 29 09:58:03 susetest systemd[1]: Child 13216 (snapperd) died (code=exited, status=0/SUCCESS)
Oct 29 09:58:03 susetest systemd[1]: dbus.service: Child 13216 belongs to dbus.service.
Oct 29 09:58:29 susetest systemd[1]: systemd-udevd.service: Got notification message from PID 385 (WATCHDOG=1)
Oct 29 09:58:39 susetest systemd[1]: systemd-logind.service: Got notification message from PID 866 (WATCHDOG=1)
Oct 29 09:59:39 susetest systemd[1]: systemd-journald.service: Got notification message from PID 363 (WATCHDOG=1)
Oct 29 10:00:39 susetest systemd[1]: systemd-udevd.service: Got notification message from PID 385 (WATCHDOG=1)
Oct 29 10:00:39 susetest systemd[1]: systemd-logind.service: Got notification message from PID 866 (WATCHDOG=1)
Oct 29 10:01:29 susetest systemd[1]: systemd-journald.service: Got notification message from PID 363 (WATCHDOG=1)
Oct 29 10:01:45 susetest kernel: sysrq: SysRq : Show Blocked State
Oct 29 10:01:45 susetest kernel: task PC stack pid father
Oct 29 10:01:45 susetest kernel: kglobalaccel5 D 0 12766 1275 0x00000000
Oct 29 10:01:45 susetest kernel: Call Trace:
Oct 29 10:01:45 susetest kernel: ? __schedule+0x29a/0x880
Oct 29 10:01:45 susetest kernel: schedule+0x2f/0x90
Oct 29 10:01:45 susetest kernel: io_schedule+0x12/0x40
Oct 29 10:01:45 susetest kernel: __lock_page_or_retry+0x174/0x2e0
Oct 29 10:01:45 susetest kernel: ? radix_tree_lookup_slot+0xe/0x20
Oct 29 10:01:45 susetest kernel: ? page_cache_tree_insert+0xb0/0xb0
Oct 29 10:01:45 susetest kernel: filemap_fault+0x14f/0x740
Oct 29 10:01:45 susetest kernel: ? filemap_map_pages+0x1f6/0x390
Oct 29 10:01:45 susetest kernel: __do_fault+0x20/0xe0
Oct 29 10:01:45 susetest kernel: handle_pte_fault+0x931/0xff0
Oct 29 10:01:45 susetest kernel: __handle_mm_fault+0x3ed/0x540
Oct 29 10:01:45 susetest kernel: handle_mm_fault+0xfd/0x240
Oct 29 10:01:45 susetest kernel: __do_page_fault+0x211/0x4e0
Oct 29 10:01:45 susetest kernel: ? async_page_fault+0x8/0x30
Oct 29 10:01:45 susetest kernel: async_page_fault+0x1e/0x30
Oct 29 10:01:45 susetest kernel: RIP: 0033:0x7f35a1da0f10
Oct 29 10:01:45 susetest kernel: Code: Bad RIP value.
Oct 29 10:01:45 susetest kernel: RSP: 002b:00007ffd9309aaa8 EFLAGS: 00010206
Oct 29 10:01:45 susetest kernel: RAX: 0000000000000000 RBX: 00007f3594005670 RCX: 00007f359c819ad8
Oct 29 10:01:45 susetest kernel: RDX: 00007f3594005670 RSI: 00007f359ab320db RDI: 0000000000000013
Oct 29 10:01:45 susetest kernel: RBP: 000055e28db475f0 R08: 000055e28dc4ec50 R09: 0000000000000000
Oct 29 10:01:45 susetest kernel: R10: 0000000000000001 R11: 0000000000000000 R12: 000055e28db3d090
Oct 29 10:01:45 susetest kernel: R13: 00007f3594005670 R14: 00007ffd9309ab68 R15: 000055e28db3d7f0
Oct 29 10:01:47 susetest systemd-logind[866]: VT changed to 5
Oct 29 10:01:47 susetest systemd-logind[866]: Sent message type=signal sender=n/a destination=n/a
path=/org/freedesktop/login1/session/_37 interface=org.freedesktop.DBus.Properties member=PropertiesChanged
cookie=510 reply_cookie=0 signature=sa{sv}as error-
systemd is started with log level debug:¶
Oct 29 09:17:14 linux-shhx kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-4.18.15-1-default
root=UUID=427af700-989b-448a-91d5-2b6f10627ffb splash=silent video=1024x768-16 plymouth.ignore-serial-consoles
console=ttyS0 console=tty systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M printk.devkmsg=on
enforcing=0 resume=/dev/disk/by-path/pci-0000:00:08.0-part4 quiet
The log level is apparently set during the installation:
https://openqa.opensuse.org/tests/783612#step/disable_grub_timeout/9
Reproducible¶
Fails since (at least) Build 20181023
Expected result¶
Last good: 20181022 (or more recent)
Further details¶
Always latest result in this scenario: latest
Updated by okurz over 5 years ago
- Subject changed from test fails in kate - excessive systemd debug level? to [functional][y] test fails in kate - excessive systemd debug level?
- Assignee set to oorlov
- Target version set to Milestone 21
@oorlov I assume this is since you increased systemd debugging info in shutdown?
Updated by oorlov over 5 years ago
Well, DEBUG_SHUTDOWN=1 is applied for the kde test suite and sets 'systemd.log_level=debug systemd.log_target=kmsg' in boot.
If it is the issue, then DEBUG_SHUTDOWN could be removed. And it actually has to be removed, as it was added to gather shutdown failing statistics, but shutdown is not failing anymore there.
The other question is why "Kate" module fails more then the others and on the same KRunner call? KRunner simply does not show prompt on typing. Does logging can load system so much?
Updated by oorlov over 5 years ago
- Status changed from New to Feedback
I've removed the DEBUG_SHUTDOWN from kde scenario. Will monitor the kde issue in the next runs.
Updated by oorlov over 5 years ago
- Status changed from Feedback to Resolved
Test is not failed anymore.
Updated by okurz over 5 years ago
- Status changed from Resolved to Feedback
so does that mean that there can not be any "excessive systemd debug" information anymore?
Updated by okurz over 5 years ago
- Status changed from Feedback to Resolved
As confirmed by oorlov: Yes, that means that the excessing systemd debugging is prevented.