1019751 – abrt sometimes do not catch kernel oops

Bug 1019751 - abrt sometimes do not catch kernel oops

Summary: abrt sometimes do not catch kernel oops

Keywords:
Status:	CLOSED NOTABUG
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	abrt
Sub Component:
Version:	19
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	---
Assignee:	abrt
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2013-10-16 10:58 UTC by Jan Hutař
Modified:	2013-10-17 14:52 UTC (History)
CC List:	8 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2013-10-17 10:45:41 UTC
Type:	Bug
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Description Jan Hutař 2013-10-16 10:58:57 UTC

Description of problem:
When you generate multiple kernel oops in row some might not be noticed by abrt.


Version-Release number of selected component (if applicable):
abrt-2.1.8-1.fc19.x86_64
kernel-3.11.4-201.fc19.x86_64


How reproducible:
About 1 of 20 oopses (guessing)


Steps to Reproduce:
1. Run following loop and wait few seconds until it stuck in "waiting" mode
while true; do
  echo "===== START ====="
  abrt-cli list
  t=$( mktemp )
  cat kernel-oops.log \
    | sed "s/kenel-version-placeholder/$( uname -r -v|awk '{print $1,$2}' )/" \
    | sed "s/^prefix/$( date +"%a %d %H:%M:%S" ) $( hostname -s )/"\
    >> /var/log/messages
  abrt-cli list
  stat $t /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0/count
  while [ $t -nt /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0/count ]; do
    echo "waiting"
    sleep 1
  done
  abrt-cli list
  stat $t /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0/count
  echo "===== END ====="
done


Actual results:
===== START =====
id d1260a3a3577410de214a28dec7ba61af54694b0
Directory:      /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0
count:          19
package:        kernel
time:           Thu 17 Oct 2013 04:06:46 PM EDT
id d1260a3a3577410de214a28dec7ba61af54694b0
Directory:      /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0
count:          19
package:        kernel
time:           Thu 17 Oct 2013 04:06:46 PM EDT
  File: ‘/tmp/tmp.B0CCGVPcyw’
  Size: 0         	Blocks: 0          IO Block: 4096   regular empty file
Device: 20h/32d	Inode: 2678509     Links: 1
Access: (0600/-rw-------)  Uid: (    0/    root)   Gid: (    0/    root)
Context: unconfined_u:object_r:user_tmp_t:s0
Access: 2013-10-17 16:24:06.039234373 -0400
Modify: 2013-10-17 16:24:06.039234373 -0400
Change: 2013-10-17 16:24:06.039234373 -0400
 Birth: -
  File: ‘/var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0/count’
  Size: 2         	Blocks: 8          IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 405767      Links: 1
Access: (0664/-rw-rw-r--)  Uid: (    0/    root)   Gid: (    0/    root)
Context: system_u:object_r:abrt_var_cache_t:s0
Access: 2013-10-17 16:19:28.504684229 -0400
Modify: 2013-10-17 16:19:28.485433151 -0400
Change: 2013-10-17 16:19:28.485433151 -0400
 Birth: -
waiting
waiting
id d1260a3a3577410de214a28dec7ba61af54694b0
Directory:      /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0
count:          20
package:        kernel
time:           Thu 17 Oct 2013 04:06:46 PM EDT
  File: ‘/tmp/tmp.B0CCGVPcyw’
  Size: 0         	Blocks: 0          IO Block: 4096   regular empty file
Device: 20h/32d	Inode: 2678509     Links: 1
Access: (0600/-rw-------)  Uid: (    0/    root)   Gid: (    0/    root)
Context: unconfined_u:object_r:user_tmp_t:s0
Access: 2013-10-17 16:24:06.039234373 -0400
Modify: 2013-10-17 16:24:06.039234373 -0400
Change: 2013-10-17 16:24:06.039234373 -0400
 Birth: -
  File: ‘/var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0/count’
  Size: 2         	Blocks: 8          IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 405767      Links: 1
Access: (0664/-rw-rw-r--)  Uid: (    0/    root)   Gid: (    0/    root)
Context: system_u:object_r:abrt_var_cache_t:s0
Access: 2013-10-17 16:24:08.078015270 -0400
Modify: 2013-10-17 16:24:07.104460723 -0400
Change: 2013-10-17 16:24:07.104460723 -0400
 Birth: -
===== END =====
[...]
===== START =====
id d1260a3a3577410de214a28dec7ba61af54694b0
Directory:      /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0
count:          21
package:        kernel
time:           Thu 17 Oct 2013 04:06:46 PM EDT
id d1260a3a3577410de214a28dec7ba61af54694b0
Directory:      /var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0
count:          21
package:        kernel
time:           Thu 17 Oct 2013 04:06:46 PM EDT
  File: ‘/tmp/tmp.O9IwyajWR4’
  Size: 0         	Blocks: 0          IO Block: 4096   regular empty file
Device: 20h/32d	Inode: 2679039     Links: 1
Access: (0600/-rw-------)  Uid: (    0/    root)   Gid: (    0/    root)
Context: unconfined_u:object_r:user_tmp_t:s0
Access: 2013-10-17 16:24:11.014263117 -0400
Modify: 2013-10-17 16:24:11.014263117 -0400
Change: 2013-10-17 16:24:11.014263117 -0400
 Birth: -
  File: ‘/var/tmp/abrt/oops-2013-10-17-16:06:46-11604-0/count’
  Size: 2         	Blocks: 8          IO Block: 4096   regular file
Device: fd01h/64769d	Inode: 405767      Links: 1
Access: (0664/-rw-rw-r--)  Uid: (    0/    root)   Gid: (    0/    root)
Context: system_u:object_r:abrt_var_cache_t:s0
Access: 2013-10-17 16:24:10.130546937 -0400
Modify: 2013-10-17 16:24:10.107628986 -0400
Change: 2013-10-17 16:24:10.107628986 -0400
 Birth: -
waiting
waiting
waiting
[...]
waiting
waiting
waiting
^C


Expected results:
All oopses should be noticed by abrt.


Additional info:
Oops file used to provoke oops:
# cat kernel-oops.log
prefix-placeholder kernel: [drm] Num pipes: 1
prefix-placeholder kernel: [drm] Setting GART location based on new memorymap
prefix-placeholder kernel: [drm] Loading RS690/RS740 Microcode
prefix-placeholder kernel: [drm] Num pipes: 1
prefix-placeholder kernel: [drm] writeback test succeeded in 1 usecs
prefix-placeholder kernel: [drm] Num pipes: 1
prefix-placeholder kernel: [drm] Setting GART location based on new memorymap
prefix-placeholder kernel: [drm] Loading RS690/RS740 Microcode
prefix-placeholder kernel: [drm] Num pipes: 1
prefix-placeholder kernel: [drm] writeback test succeeded in 1 usecs
prefix-placeholder kernel: [drm] Num pipes: 1
prefix-placeholder kernel: [drm:radeon_set_igpgart] *ERROR* Unable to useIGP GART table size 32768
prefix-placeholder kernel: [drm] Loading RS690/RS740 Microcode
prefix-placeholder kernel: BUG: unable to handle kernel NULL pointer dereference at 00000000
prefix-placeholder kernel: IP: [<f88dec25>] :radeon:radeon_cp_init_ring_buffer+0x90/0x302
prefix-placeholder kernel: *pde = 6f5c6067
prefix-placeholder kernel: Oops: 0000 [#1] SMP.
prefix-placeholder kernel: Modules linked in: r8169 mii fuse nfsd lockd nfs_acl auth_rpcgss exportfs bridge stp bnep sco l2cap bl
prefix-placeholder kernel: Pid: 8003, comm: Xorg Not tainted (kenel-version-placeholder)
prefix-placeholder kernel: EIP: 0060:[<f88dec25>] EFLAGS: 00213246 CPU: 1
prefix-placeholder kernel: EIP is at radeon_cp_init_ring_buffer+0x90/0x302 [radeon]
prefix-placeholder kernel: EAX: 00000000 EBX: f78b4000 ECX: f78b4000 EDX: 00000000
prefix-placeholder kernel: ESI: f5dbe800 EDI: 00006458 EBP: f0a0cf18 ESP: f0a0cf08
prefix-placeholder kernel: DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
prefix-placeholder kernel: Process Xorg (pid: 8003, ti=f0a0c000 task=f2380000 task.ti=f0a0c000)
prefix-placeholder kernel: Stack: f0a0cf18 f78b4000 f5dbe800 00006458 f0a0cf28 f88e11c7 f8911a24 00000000.
prefix-placeholder kernel:       f0a0cf4c f88745f8 f30c3ba0 f5dbe800 f88e114a f5dbe828 f890fd78 f097ac00.
prefix-placeholder kernel:       00000000 f0a0cf68 c049b1c0 00000000 00006458 f097ac00 f097ac00 00000000.
prefix-placeholder kernel: Call Trace:
prefix-placeholder kernel: [<f88e11c7>] radeon_cp_resume+0x7d/0xbc [radeon]
prefix-placeholder kernel: [<f88745f8>] drm_ioctl+0x1b0/0x225 [drm]
prefix-placeholder kernel: [<f88e114a>] radeon_cp_resume+0x0/0xbc [radeon]
prefix-placeholder kernel: [<c049b1c0>] vfs_ioctl+0x50/0x69
prefix-placeholder kernel: [<c049b414>] do_vfs_ioctl+0x23b/0x247
prefix-placeholder kernel: [<c0460a56>] audit_syscall_entry+0xf9/0x123
prefix-placeholder kernel: [<c049b460>] sys_ioctl+0x40/0x5c
prefix-placeholder kernel: [<c0403c76>] syscall_call+0x7/0xb
prefix-placeholder kernel: =======================
prefix-placeholder kernel: Code: 66 31 d2 09 c2 89 d8 e8 fc e7 ff ff 8b 83 cc 00 00 00 8b 53 34 03 10 8b 86 70 02 00 00 2b  50 44
prefix-placeholder kernel: EIP: [<f88dec25>] radeon_cp_init_ring_buffer+0x90/0x302 [radeon] SS:ESP 0068:f0a0cf08
prefix-placeholder kernel: ---[ end trace 81e3cf9431f7af0c ]---

Comment 2 Jakub Filak 2013-10-16 11:52:07 UTC

Thank you for taking the time to report this issue. Actually, this is not a bug, it is a feature. ABRT limits number of detected oopses and protects your system from wasting of CPU time and disk space. It is quite common that kernel oopses come in a group of hundreds and you definitely do not want to detect all of them. For more details see bug 902398

Comment 3 Jan Hutař 2013-10-17 14:52:03 UTC

Thanks for explanation. This is a NOTABUG then.

Note You need to log in before you can comment on or make changes to this bug.