Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 666990

Summary: abrt doesn't include enough debugging info when filing kernel reports
Product: Red Hat Enterprise Linux 6 Reporter: James M. Leddy <james.leddy>
Component: abrtAssignee: Jiri Moskovcak <jmoskovc>
Status: CLOSED NOTABUG QA Contact: BaseOS QE - Apps <qe-baseos-apps>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.0CC: dfediuck, dvlasenk, gavin, gborsuk, james.leddy, kklic, npajkovs, rvokal
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 666264 Environment:
Last Closed: 2011-01-25 17:05:48 UTC Type: ---
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: 666264    
Bug Blocks:    

Description James M. Leddy 2011-01-03 23:28:12 UTC
+++ This bug was initially created as a clone of Bug #666264 +++

Description of problem:
Kernel warning occurs when resuming from sleep.  This may only be a warning message and therefore nothing to fix; however, this event triggers an ABRT warning so, IMHO, we need to either correct the condition that causes the warning message or we need to tweak ABRT to disregard warning messages. I suspect this situation will lead to many tickets being filed once RHEL6 becomes more widely deployed.  One case has already been opened against this during the beta. BZ620026

Version-Release number of selected component (if applicable):
kernel-2.6.32-71.el6.x86_64

How reproducible:
Every time

Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:
architecture: x86_64
cmdline: not_applicable
comment: Not sure if the docking station is necessary to reproduce this or not.
component: kernel
executable: kernel
kernel: 2.6.32-71.el6.x86_64
package: kernel
reason: WARNING: at kernel/trace/ring_buffer.c:1987 rb_reserve_next_event+0x2b2/0x350() (Tainted: G        W  ---------------- )
release: Red Hat Enterprise Linux Workstation release 6.0 (Santiago)
sosreport.tar.xz: /var/spool/abrt/kerneloops-1291124686-2417-1/sosreport.tar.xz
time: 1291507840
uid: 0

backtrace
-----
WARNING: at kernel/trace/ring_buffer.c:1987 rb_reserve_next_event+0x2b2/0x350() (Tainted: G        W  ---------------- )
Hardware name: 2241B36
Modules linked in: authenc deflate zlib_deflate ctr camellia cast5 rmd160 crypto_null ccm serpent blowfish twofish_x86_64 twofish_common xcbc cbc sha256_generic sha512_generic des_generic tunnel4 xfrm_ipcomp tunnel6 ext2 fuse rfcomm sco bridge bnep l2cap autofs4 sunrpc fcoe libfcoe 8021q garp libfc stp llc scsi_transport_fc scsi_tgt cpufreq_ondemand acpi_cpufreq freq_table cachefiles fscache ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables ipv6 dm_mirror dm_region_hash dm_log kvm uinput thinkpad_acpi hwmon wmi btusb bluetooth sg uvcvideo videodev v4l2_compat_ioctl32 i2c_i801 iTCO_wdt iTCO_vendor_support arc4 ecb iwlagn iwlcore mac80211 cfg80211 rfkill snd_hda_codec_conexant snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm snd_timer snd soundcore snd_page_alloc e1000e ext4 mbcache jbd2 cryptd aes_x86_64 aes_generic xts gf128mul dm_crypt sr_mod cdrom sd_mod crc_t10di
f sdhci_pci sdhci mmc_core firewire_ohci firewire_core crc_itu_t yenta_socket rsrc_nonstatic ahci usb_storage i915 drm_kms_helper drm i2c_algo_bit i2c_core video output dm_mod [last unloaded: af_key]
Pid: 24887, comm: pm-suspend Tainted: G        W  ----------------  2.6.32-71.el6.x86_64 #1
Call Trace:
[<ffffffff8106b857>] warn_slowpath_common+0x87/0xc0
[<ffffffff8106b8aa>] warn_slowpath_null+0x1a/0x20
[<ffffffff810e9a62>] rb_reserve_next_event+0x2b2/0x350
[<ffffffff810e9cb2>] ring_buffer_lock_reserve+0xa2/0x160
[<ffffffff810ebbec>] trace_buffer_lock_reserve+0x2c/0x70
[<ffffffff810ebe36>] trace_current_buffer_lock_reserve+0x16/0x20
[<ffffffff810aa67b>] ftrace_raw_event_id_module_refcnt+0x6b/0x100
[<ffffffff813dbeea>] ? cpufreq_cpu_get+0x8a/0x160
[<ffffffff810aa728>] ftrace_raw_event_module_get+0x18/0x20
[<ffffffff813dbfa8>] cpufreq_cpu_get+0x148/0x160
[<ffffffff813dc02d>] cpufreq_resume+0x6d/0xc0
[<ffffffff8132c52e>] __sysdev_resume+0x4e/0xe0
[<ffffffff8132c649>] sysdev_resume+0x89/0x190
[<ffffffff810b2002>] suspend_devices_and_enter+0x162/0x1b0
[<ffffffff810b2172>] enter_state+0x122/0x190
[<ffffffff810b17da>] state_store+0x9a/0x100
[<ffffffff8125aaa7>] kobj_attr_store+0x17/0x20
[<ffffffff811df145>] sysfs_write_file+0xe5/0x170
[<ffffffff8116c818>] vfs_write+0xb8/0x1a0
[<ffffffff8116d251>] sys_write+0x51/0x90
[<ffffffff81013387>] tracesys+0xd9/0xde

reproduce
-----
1.  Disconnect power from laptop
2.  Allow laptop to go into sleep mode
3.  Reconnect laptop to power (in my case a docking station)
4.  Resume the laptop

Also it appears that this was reported

--- Additional comment from pm-rhel on 2010-12-29 17:53:16 EST ---

Since this issue was entered in bugzilla, the release flag has been
set to ? to ensure that it is properly evaluated for this release.

--- Additional comment from james.leddy on 2010-12-30 13:21:15 EST ---

Dave, was this report filed from ABRT? If so we have two bugs, ABRT did not report everything from the --[ please cut here ]-- line. 

This is regarding timestamps:

1981        if (unlikely(*delta > (1ULL << 59) && !once++)) {
1982                printk(KERN_WARNING "Delta way too big! %llu"
1983                       " ts=%llu write stamp = %llu\n",
1984                       (unsigned long long)*delta,
1985                       (unsigned long long)*ts,
1986                       (unsigned long long)cpu_buffer->write_stamp);
1987                WARN_ON(1);
1988        }
1989

As far as the ring buffer is concerned, we either need a way for the ring buffer to know that the computer was suspended recently, or we need to get rid of that warning entirely.

--- Additional comment from dmair on 2011-01-03 09:48:33 EST ---

(In reply to comment #2)
> Dave, was this report filed from ABRT? If so we have two bugs, ABRT did not
> report everything from the --[ please cut here ]-- line. 
> 
> This is regarding timestamps:
> 
> 1981        if (unlikely(*delta > (1ULL << 59) && !once++)) {
> 1982                printk(KERN_WARNING "Delta way too big! %llu"
> 1983                       " ts=%llu write stamp = %llu\n",
> 1984                       (unsigned long long)*delta,
> 1985                       (unsigned long long)*ts,
> 1986                       (unsigned long long)cpu_buffer->write_stamp);
> 1987                WARN_ON(1);
> 1988        }
> 1989
> 
> As far as the ring buffer is concerned, we either need a way for the ring
> buffer to know that the computer was suspended recently, or we need to get rid
> of that warning entirely.

@James M. Leddy:

Yes, this was reported by ABRT -- I would not have even been aware there was a problem if ABRT had not brought it to my attention. I'd agree if ABRT is not including everything then we have two bugs here.

Comment 2 James M. Leddy 2011-01-03 23:34:36 UTC
see bug #666264 comment #3

The "Delta way too big!" message is not included in the report. If customers saw this part of the log, they may be able to more easily piece together what happened.

Comment 3 Denys Vlasenko 2011-01-04 10:54:49 UTC
I assume dmesg looks like this:


Delta way too big! 1234567890 ts=9876543211 write stamp = 123456789
------------[ cut here ]------------
WARNING: at kernel/trace/ring_buffer.c:1987 rb_reserve_next_event+0x2b2/0x350()
(Tainted: G        W  ---------------- )
Hardware name: 2241B36
...
...
...


More generally, WARN_ON(cond) will result in this log:

prev msgs
prev msgs
prev msgs
------------[ cut here ]------------
WARNING: at path/to/file.c:1234 func+0xOFS/0xLEN()
...
...
...


We have a problem here: we do not know whether "prev msgs" contain any useful information pertaining to this WARN_ON() - and if they do, how many lines?

It is easy to change abrt so that it grabs N previous lines above "WARNING: at" line. The question is, how big N should be?

Comment 4 James M. Leddy 2011-01-04 17:31:43 UTC
Good question. I suppose I could try to replicate the results that Dave has seen and get back to you.

(In reply to comment #3)
> I assume dmesg looks like this:
> 
> 
> Delta way too big! 1234567890 ts=9876543211 write stamp = 123456789
> ------------[ cut here ]------------
> WARNING: at kernel/trace/ring_buffer.c:1987 rb_reserve_next_event+0x2b2/0x350()
> (Tainted: G        W  ---------------- )
> Hardware name: 2241B36
> ...
> ...
> ...

Good question. That's accurate according to this bug report: 

https://bugs.launchpad.net/ubuntu/+source/linux/+bug/458957
> 
> 
> More generally, WARN_ON(cond) will result in this log:
> 
> prev msgs
> prev msgs
> prev msgs
> ------------[ cut here ]------------
> WARNING: at path/to/file.c:1234 func+0xOFS/0xLEN()
> ...
> ...
> ...
> 
> 
> We have a problem here: we do not know whether "prev msgs" contain any useful
> information pertaining to this WARN_ON() - and if they do, how many lines?
> 
> It is easy to change abrt so that it grabs N previous lines above "WARNING: at"
> line. The question is, how big N should be?

Don't know. Presumably interesting stuff is only at warning level. And if "prev msgs" were 10 minutes ago, they probably aren't relevant. So ideal solution is to filter around time of WARNING: and log level, if that's possible.

Comment 5 James M. Leddy 2011-01-05 16:22:38 UTC
Semi related,

Please include the --[ cut here ]-- and end trace uuid. Several tools, including abrt ko plugin, use these markers.

Comment 6 James M. Leddy 2011-01-25 17:05:48 UTC
I'm of the belief that this is a bug in the kernel and should be fixed as it crops up. You can see a better way of using WARN_ON in bug 672526 where the message follows the --[please cut here]-- line.