Bug 981048

Summary: RFE: introduce journal command that dumps kernel: [ cut here ]/[ end trace] entries from the journal
Product: [Fedora] Fedora Reporter: Jóhann B. Guðmundsson <johannbg>
Component: systemdAssignee: systemd-maint
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: johannbg, lnykryn, msekleta, notting, plautrba, systemd-maint, vpavlin, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-07-26 01:43:44 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 784611    

Description Jóhann B. Guðmundsson 2013-07-03 21:10:32 UTC
Description of problem:

The summary kinda says it all. 

It would be extremely useful to be able to run something like... 

"journalctl -ktrace" 

that would dump all existing entries like this from the journal

kernel: ------------[ cut here ]------------
kernel: WARNING: at drivers/gpu/drm/i915/intel_pm.c:4355 
kernel: Hardware name: 4180WPD
kernel: MMIO read or write has been dropped 3
kernel: Modules linked in: fuse ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat_ipv4 nf_nat nf
kernel:  sdhci_pci sdhci firewire_ohci drm mmc_core firewire_core crc_itu_t i2c_core wmi video
kernel: Pid: 1781, comm: kworker/u:0 Tainted: G        W    3.9.6-200.fc18.x86_64 #1
kernel: Call Trace:
kernel:  [<ffffffff8105ef85>] warn_slowpath_common+0x75/0xa0
kernel:  [<ffffffff8105f066>] warn_slowpath_fmt+0x46/0x50kernel:  [<ffffffffa013e131>] gen6_gt_check_fifodbg+0x41/0x60 [i915]
kernel:  [<ffffffffa013e174>] __gen6_gt_force_wake_put+0x24/0x30 [i915]
kernel:  [<ffffffffa013e217>] gen6_gt_force_wake_put+0x37/0x50 [i915]
kernel:  [<ffffffffa0142b52>] init_ring_common+0x222/0x3b0 [i915]
kernel:  [<ffffffffa0102748>] ? i915_gem_reset_fences+0x78/0xf0 [i915]
kernel:  [<ffffffffa01433d4>] init_render_ring+0x34/0x390 [i915]
kernel:  [<ffffffffa00f1aa2>] i915_reset+0xf2/0x1a0 [i915]
kernel:  [<ffffffffa00f6fbd>] i915_error_work_func+0xcd/0x160 [i915]
kernel:  [<ffffffff8107b623>] process_one_work+0x173/0x3c0
kernel:  [<ffffffff8107cf4f>] worker_thread+0x10f/0x390
kernel:  [<ffffffff8107ce40>] ? busy_worker_rebind_fn+0xb0/0xb0
kernel:  [<ffffffff81082af0>] kthread+0xc0/0xd0
kernel:  [<ffffffff81090168>] ? finish_task_switch+0x48/0xe0
kernel:  [<ffffffff81010000>] ? ftrace_define_fields_xen_mc_flush+0x20/0xb0
kernel:  [<ffffffff81082a30>] ? kthread_create_on_node+0x120/0x120
kernel:  [<ffffffff8166a52c>] ret_from_fork+0x7c/0xb0
kernel:  [<ffffffff81082a30>] ? kthread_create_on_node+0x120/0x120
kernel: ---[ end trace 2f46923b1afdabcc ]---

( yes I have been going through several of drm/intel relate crashes which started with 3.9.x and are still present with 3.10.x like this hence the suggestion ) 

Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Comment 1 Zbigniew Jędrzejewski-Szmek 2013-07-04 12:35:57 UTC
Try this ;)

------------[ cut here ]------------
#!/usr/bin/python

from __future__ import print_function
import re

from systemd import journal
j = journal.Reader()
first = True

while True:
    j.add_match('_TRANSPORT=kernel')
    j.add_match(MESSAGE='------------[ cut here ]------------')
    line = j.get_next()
    if not line:
        break

    j.flush_matches()
    j.add_match('_TRANSPORT=kernel')

    if first:
        first = False
    else:
        print()

    while line:
        print(line['MESSAGE'])
        if re.match(r'---\[ end trace [a-z0-9]+ \]---', line['MESSAGE']):
            break
        line = j.get_next()

---[ end trace deadbeef ]---

If generally useful, we could make this into a proper script and stick it in systemd. What kind of functionality would you need? Last trace? Last n traces? Traces from this boot? Save to a file? Postprocess somehow?

Comment 2 Jóhann B. Guðmundsson 2013-07-04 14:50:43 UTC
Well the general idea here is to make it super easy to report those traces so I would assume only uniq traces would be useful and save to file and potentially flush entries or somehow flag it having being saved ( to prevent report duplicates by reporters themselves ) from journal to attach to bug report.

I would assume tools like ABRT would take advantage of this or use this somehow as well.

Comment 3 Lennart Poettering 2013-07-26 01:43:44 UTC
Nah, this is nothing we ever want to do in the journal itself: detect messages by their text contents. 

I can see the usefulness for this, but people should user message_ids for that, nothing else. Of course it's difficult convincing kernel folks about that, but I still don't think we should work around that.

Comment 4 Lennart Poettering 2013-07-26 01:44:46 UTC
Also note that abrt does something like this anyway, afaik, to process the messages further. I don't think we need to do this in journald itself, as it couldn't do anything with that data anyway, but abrt can.