Bug 1266661 - Why abrt not catch kernel crash?
Summary: Why abrt not catch kernel crash?
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: abrt
Version: 25
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: abrt
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-09-26 09:27 UTC by Mikhail
Modified: 2018-01-22 12:36 UTC (History)
11 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-12-12 11:12:52 UTC
Type: Bug


Attachments (Terms of Use)
dmesg (268.29 KB, text/plain)
2015-09-26 09:27 UTC, Mikhail
no flags Details

Description Mikhail 2015-09-26 09:27:15 UTC
Description of problem:

I see in dmesg log messages:

[  233.467351] usb 1-9.1.3: ep 0x82 - rounding interval to 64 microframes, ep desc says 80 microframes

[  233.469146] ======================================================
[  233.469148] [ INFO: possible circular locking dependency detected ]
[  233.469150] 4.2.1-300.fc23.x86_64+debug #1 Not tainted
[  233.469151] -------------------------------------------------------
[  233.469153] V4L2CaptureThre/5173 is trying to acquire lock:
[  233.469154]  (s_active#18){++++.+}, at: [<ffffffff812fd0e9>] kernfs_remove_by_name_ns+0x49/0xa0
[  233.469164] 
               but task is already holding lock:
[  233.469165]  (&gspca_dev->queue_lock){+.+.+.}, at: [<ffffffffa04e4b84>] vidioc_streamon+0x44/0xe0 [gspca_main]
[  233.469171] 
               which lock already depends on the new lock.

[  233.469173] 
               the existing dependency chain (in reverse order) is:
[  233.469175] 
               -> #2 (&gspca_dev->queue_lock){+.+.+.}:
[  233.469178]        [<ffffffff8110aac7>] lock_acquire+0xc7/0x270
[  233.469182]        [<ffffffff8186da6f>] mutex_lock_interruptible_nested+0x7f/0x460
[  233.469186]        [<ffffffffa04e37b6>] dev_mmap+0x56/0x250 [gspca_main]
[  233.469188]        [<ffffffffa07dd114>] v4l2_mmap+0x54/0x90 [videodev]
[  233.469193]        [<ffffffff812248cb>] mmap_region+0x3eb/0x670
[  233.469197]        [<ffffffff81224e5f>] do_mmap_pgoff+0x30f/0x3f0
[  233.469199]        [<ffffffff81206dbd>] vm_mmap_pgoff+0xad/0xe0
[  233.469201]        [<ffffffff81223202>] SyS_mmap_pgoff+0x1f2/0x290
[  233.469204]        [<ffffffff81022d2b>] SyS_mmap+0x1b/0x30
[  233.469207]        [<ffffffff81871d6e>] entry_SYSCALL_64_fastpath+0x12/0x76
[  233.469210] 
               -> #1 (&mm->mmap_sem){++++++}:
[  233.469213]        [<ffffffff8110aac7>] lock_acquire+0xc7/0x270
[  233.469216]        [<ffffffff81218f0a>] __might_fault+0x7a/0xa0
[  233.469219]        [<ffffffff812fdc6f>] kernfs_fop_write+0x8f/0x190
[  233.469221]        [<ffffffff8126fbc7>] __vfs_write+0x37/0x100
[  233.469225]        [<ffffffff812705d9>] vfs_write+0xa9/0x1a0
[  233.469227]        [<ffffffff812712f8>] SyS_write+0x58/0xd0
[  233.469229]        [<ffffffff81871d6e>] entry_SYSCALL_64_fastpath+0x12/0x76
[  233.469231] 
               -> #0 (s_active#18){++++.+}:
[  233.469235]        [<ffffffff81109eb8>] __lock_acquire+0x1a78/0x1d00
[  233.469237]        [<ffffffff8110aac7>] lock_acquire+0xc7/0x270
[  233.469240]        [<ffffffff812fc398>] __kernfs_remove+0x288/0x380
[  233.469242]        [<ffffffff812fd0e9>] kernfs_remove_by_name_ns+0x49/0xa0
[  233.469244]        [<ffffffff812feaf5>] sysfs_remove_file_ns+0x15/0x20
[  233.469247]        [<ffffffff81576778>] device_del+0x138/0x270
[  233.469249]        [<ffffffff815768d2>] device_unregister+0x22/0x70
[  233.469251]        [<ffffffff81620fb3>] usb_remove_ep_devs+0x23/0x40
[  233.469255]        [<ffffffff81619681>] remove_intf_ep_devs+0x41/0x60
[  233.469258]        [<ffffffff8161a45a>] usb_set_interface+0x19a/0x390
[  233.469260]        [<ffffffffa04e45c3>] gspca_init_transfer+0x4d3/0xa50 [gspca_main]
[  233.469263]        [<ffffffffa04e4be0>] vidioc_streamon+0xa0/0xe0 [gspca_main]
[  233.469265]        [<ffffffffa07de95a>] v4l_streamon+0x1a/0x20 [videodev]
[  233.469269]        [<ffffffffa07e223d>] __video_do_ioctl+0x29d/0x310 [videodev]
[  233.469272]        [<ffffffffa07e42c2>] video_usercopy+0x3c2/0x830 [videodev]
[  233.469276]        [<ffffffffa07e4745>] video_ioctl2+0x15/0x20 [videodev]
[  233.469279]        [<ffffffffa07dd693>] v4l2_ioctl+0xb3/0xe0 [videodev]
[  233.469283]        [<ffffffff812858ae>] do_vfs_ioctl+0x2ee/0x550
[  233.469286]        [<ffffffff81285b89>] SyS_ioctl+0x79/0x90
[  233.469288]        [<ffffffff81871d6e>] entry_SYSCALL_64_fastpath+0x12/0x76
[  233.469291] 
               other info that might help us debug this:

[  233.469292] Chain exists of:
                 s_active#18 --> &mm->mmap_sem --> &gspca_dev->queue_lock

[  233.469296]  Possible unsafe locking scenario:

[  233.469298]        CPU0                    CPU1
[  233.469299]        ----                    ----
[  233.469299]   lock(&gspca_dev->queue_lock);
[  233.469301]                                lock(&mm->mmap_sem);
[  233.469303]                                lock(&gspca_dev->queue_lock);
[  233.469305]   lock(s_active#18);
[  233.469308] 
                *** DEADLOCK ***

[  233.469310] 2 locks held by V4L2CaptureThre/5173:
[  233.469312]  #0:  (&gspca_dev->usb_lock){+.+.+.}, at: [<ffffffffa07dd63f>] v4l2_ioctl+0x5f/0xe0 [videodev]
[  233.469317]  #1:  (&gspca_dev->queue_lock){+.+.+.}, at: [<ffffffffa04e4b84>] vidioc_streamon+0x44/0xe0 [gspca_main]
[  233.469321] 
               stack backtrace:
[  233.469324] CPU: 1 PID: 5173 Comm: V4L2CaptureThre Not tainted 4.2.1-300.fc23.x86_64+debug #1
[  233.469326] Hardware name: Gigabyte Technology Co., Ltd. Z87M-D3H/Z87M-D3H, BIOS F11 08/12/2014
[  233.469327]  0000000000000000 0000000070c5bea1 ffff88062c59b778 ffffffff818682b6
[  233.469330]  0000000000000000 ffffffff82ae02c0 ffff88062c59b7c8 ffffffff811069c3
[  233.469333]  0000000000000000 ffff88062c59b828 0000000000000002 ffff880631fab368
[  233.469336] Call Trace:
[  233.469340]  [<ffffffff818682b6>] dump_stack+0x4c/0x65
[  233.469343]  [<ffffffff811069c3>] print_circular_bug+0x1e3/0x250
[  233.469345]  [<ffffffff81109eb8>] __lock_acquire+0x1a78/0x1d00
[  233.469348]  [<ffffffff81026d49>] ? sched_clock+0x9/0x10
[  233.469351]  [<ffffffff8110aac7>] lock_acquire+0xc7/0x270
[  233.469353]  [<ffffffff812fd0e9>] ? kernfs_remove_by_name_ns+0x49/0xa0
[  233.469355]  [<ffffffff812fc398>] __kernfs_remove+0x288/0x380
[  233.469358]  [<ffffffff812fd0e9>] ? kernfs_remove_by_name_ns+0x49/0xa0
[  233.469360]  [<ffffffff812fb447>] ? kernfs_name_hash+0x17/0xa0
[  233.469362]  [<ffffffff812fbe6c>] ? kernfs_find_ns+0x9c/0x140
[  233.469365]  [<ffffffff812fd0e9>] kernfs_remove_by_name_ns+0x49/0xa0
[  233.469367]  [<ffffffff812feaf5>] sysfs_remove_file_ns+0x15/0x20
[  233.469369]  [<ffffffff81576778>] device_del+0x138/0x270
[  233.469371]  [<ffffffff81107eed>] ? mark_held_locks+0x7d/0xb0
[  233.469373]  [<ffffffff815768d2>] device_unregister+0x22/0x70
[  233.469375]  [<ffffffff81620fb3>] usb_remove_ep_devs+0x23/0x40
[  233.469378]  [<ffffffff81619681>] remove_intf_ep_devs+0x41/0x60
[  233.469380]  [<ffffffff8161a45a>] usb_set_interface+0x19a/0x390
[  233.469382]  [<ffffffff81617998>] ? urb_destroy+0x28/0x30
[  233.469385]  [<ffffffffa04e45c3>] gspca_init_transfer+0x4d3/0xa50 [gspca_main]
[  233.469388]  [<ffffffff81108049>] ? trace_hardirqs_on_caller+0x129/0x1b0
[  233.469390]  [<ffffffffa04e4b84>] ? vidioc_streamon+0x44/0xe0 [gspca_main]
[  233.469393]  [<ffffffffa04e4be0>] vidioc_streamon+0xa0/0xe0 [gspca_main]
[  233.469396]  [<ffffffffa07de95a>] v4l_streamon+0x1a/0x20 [videodev]
[  233.469400]  [<ffffffffa07e223d>] __video_do_ioctl+0x29d/0x310 [videodev]
[  233.469404]  [<ffffffffa07e42c2>] video_usercopy+0x3c2/0x830 [videodev]
[  233.469407]  [<ffffffff81107eed>] ? mark_held_locks+0x7d/0xb0
[  233.469410]  [<ffffffffa07e1fa0>] ? v4l_querycap+0x60/0x60 [videodev]
[  233.469413]  [<ffffffff811080dd>] ? trace_hardirqs_on+0xd/0x10
[  233.469416]  [<ffffffffa07dd63f>] ? v4l2_ioctl+0x5f/0xe0 [videodev]
[  233.469419]  [<ffffffffa07dd63f>] ? v4l2_ioctl+0x5f/0xe0 [videodev]
[  233.469423]  [<ffffffffa07e4745>] video_ioctl2+0x15/0x20 [videodev]
[  233.469426]  [<ffffffffa07dd693>] v4l2_ioctl+0xb3/0xe0 [videodev]
[  233.469428]  [<ffffffff812858ae>] do_vfs_ioctl+0x2ee/0x550
[  233.469431]  [<ffffffff813a09eb>] ? selinux_file_ioctl+0x5b/0xf0
[  233.469433]  [<ffffffff81285b89>] SyS_ioctl+0x79/0x90
[  233.469436]  [<ffffffff81871d6e>] entry_SYSCALL_64_fastpath+0x12/0x76
[  557.672932] kworker/dying (3820) used greatest stack depth: 10168 bytes left
[  902.395125] kworker/dying (126) used greatest stack depth: 9864 bytes left
[ 1101.141470] kworker/dying (140) used greatest stack depth: 9856 bytes left

But abrt not catch this.

Comment 1 Mikhail 2015-09-26 09:27:40 UTC
Created attachment 1077338 [details]
dmesg

Comment 2 Matej Habrnal 2015-09-29 09:45:57 UTC
Thank you for the bug report!

ABRT didn't catch the crash because a string "[ INFO: possible circular locking dependency detected ]" is not listed in suspicious strings which ABRT uses to find a kernel crashes in log files.

ABRT is not prepared for such a format of crash log as is mentioned above in "Description of problem". If I add the "[ INFO: possible circular locking dependency detected ]" into kernel's suspicious strings, ABRT catch only following:

[ INFO: possible circular locking dependency detected ]
4.2.1-300.fc23.x86_64+debug #1 Not tainted
-------------------------------------------------------
V4L2CaptureThre/5173 is trying to acquire lock:
 (s_active#18){++++.+}, at: [<ffffffff812fd0e9>] kernfs_remove_by_name_ns+0x49/0xa0
               but task is already holding lock:
 (&gspca_dev->queue_lock){+.+.+.}, at: [<ffffffffa04e4b84>] vidioc_streamon+0x44/0xe0 [gspca_main]
               which lock already depends on the new lock.
               the existing dependency chain (in reverse order) is:
               -> #2 (&gspca_dev->queue_lock){+.+.+.}:
       [<ffffffff8110aac7>] lock_acquire+0xc7/0x270
       [<ffffffff8186da6f>] mutex_lock_interruptible_nested+0x7f/0x460
       [<ffffffffa04e37b6>] dev_mmap+0x56/0x250 [gspca_main]
       [<ffffffffa07dd114>] v4l2_mmap+0x54/0x90 [videodev]
       [<ffffffff812248cb>] mmap_region+0x3eb/0x670
       [<ffffffff81224e5f>] do_mmap_pgoff+0x30f/0x3f0
       [<ffffffff81206dbd>] vm_mmap_pgoff+0xad/0xe0
       [<ffffffff81223202>] SyS_mmap_pgoff+0x1f2/0x290
       [<ffffffff81022d2b>] SyS_mmap+0x1b/0x30
       [<ffffffff81871d6e>] entry_SYSCALL_64_fastpath+0x12/0x76

If I add a string "DEADLOCK" into kernel's suspicious strings, ABRT catch and store all the log lines which are located under "*** DEADLOCK ***" string (stack backtrace, Call Trace, ...).

To catch all the information mentioned in "Description of problem" part (from "[ INFO: possible circular locking dependency detected ]" to the end), we must   teach ABRT process such a log format. It is not a trivial and it takes some time.

So I would like to ask, is the information situated under "*** DEADLOCK ***" enough to fix the bug or we must teach ABRT to be able parse all the information (from "[ INFO: possible circular locking dependency detected ]" to the end)?

Comment 3 Anton Arapov 2015-10-16 15:48:12 UTC
Petr, do you have a courage to check this? You can check it with abrt-dump-oops tool from the Abrt. If not - let me know, I will dig into it.

Comment 4 Fedora End Of Life 2016-11-24 12:36:42 UTC
This message is a reminder that Fedora 23 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 23. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '23'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 23 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 5 Fedora End Of Life 2017-11-16 19:45:32 UTC
This message is a reminder that Fedora 25 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 25. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '25'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 25 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 6 Fedora End Of Life 2017-12-12 11:12:52 UTC
Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


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