still rcu_read_unlock bug

[rfree]

http://p.suchdig.com/p/albo-mempo106_rcubug.txt

Not tainted 3.2.66-grsec-mempo.deskmaxdbg.0.2.106 #1
3.2.66-grsec-mempo.deskmaxdbg.0.2.106 #1 SMP PREEMPT Fri Feb 6 08:34:44 UTC 2015 x86_64 GNU/Linux

Mempo 106 includes grsecurity version:
+P,ID_grsecurity_main_ID,x,grsecurity,grsecurity-3.0-3.2.66-201502052350.patch,sha256,b7deea10576f5d107750ffd3d451498e8e0546ab136afd490b05b65063948852,./tmp-path/

so this is the newest grsecurity as of today, and changelog says bug with rcu is fixed

https://github.com/mempo/mempo-kernel/c ... 4c14429706
https://raw.githubusercontent.com/mempo ... stable.txt

but still a bug can be seen:

Feb 8 14:35:14 Pbox kernel: [ 2497.895284]
Feb 8 14:35:14 Pbox kernel: [ 2497.895290] =====================================
Feb 8 14:35:14 Pbox kernel: [ 2497.895294] [ BUG: bad unlock balance detected! ]
Feb 8 14:35:14 Pbox kernel: [ 2497.895297] -------------------------------------
Feb 8 14:35:14 Pbox kernel: [ 2497.895301] java/29267 is trying to release lock (rcu_read_lock) at:
Feb 8 14:35:14 Pbox kernel: [ 2497.895310] [<ffffffff8114ac0d>] ffffffff8114ac0d
Feb 8 14:35:14 Pbox kernel: [ 2497.895313] but there are no more locks to release!
Feb 8 14:35:14 Pbox kernel: [ 2497.895316]
Feb 8 14:35:14 Pbox kernel: [ 2497.895317] other info that might help us debug this:
Feb 8 14:35:14 Pbox kernel: [ 2497.895320] no locks held by java/29267.
Feb 8 14:35:14 Pbox kernel: [ 2497.895323]
Feb 8 14:35:14 Pbox kernel: [ 2497.895324] stack backtrace:
Feb 8 14:35:14 Pbox kernel: [ 2497.895329] Pid: 29267, comm: java Not tainted 3.2.66-grsec-mempo.deskmaxdbg.0.2.106 #1
Feb 8 14:35:14 Pbox kernel: [ 2497.895333] Call Trace:
Feb 8 14:35:14 Pbox kernel: [ 2497.895346] [<ffffffff8114ac0d>] ? d_find_alias+0x5a/0x5a
Feb 8 14:35:14 Pbox kernel: [ 2497.895354] [<ffffffff810861d9>] print_unlock_inbalance_bug+0xdf/0xef
Feb 8 14:35:14 Pbox kernel: [ 2497.895360] [<ffffffff8114ac0d>] ? d_find_alias+0x5a/0x5a
Feb 8 14:35:14 Pbox kernel: [ 2497.895366] [<ffffffff81089684>] lock_release+0x11c/0x26e
Feb 8 14:35:14 Pbox kernel: [ 2497.895372] [<ffffffff8114ac29>] rcu_read_unlock+0x1c/0x29
Feb 8 14:35:14 Pbox kernel: [ 2497.895378] [<ffffffff8114c493>] shrink_dcache_parent+0x254/0x2a9
Feb 8 14:35:14 Pbox kernel: [ 2497.895385] [<ffffffff8119757c>] proc_flush_task+0x15a/0x1d2
Feb 8 14:35:14 Pbox kernel: [ 2497.895392] [<ffffffff810508ce>] release_task+0x89/0x3e0
Feb 8 14:35:14 Pbox kernel: [ 2497.895399] [<ffffffff814379dd>] ? sub_preempt_count+0x79/0xa1
Feb 8 14:35:14 Pbox kernel: [ 2497.895404] [<ffffffff810525f9>] do_exit+0x84e/0x91a
Feb 8 14:35:14 Pbox kernel: [ 2497.895410] [<ffffffff81052704>] sys_exit+0x19/0x19
Feb 8 14:35:14 Pbox kernel: [ 2497.895417] [<ffffffff814346ac>] system_call_fastpath+0x16/0x1b
Feb 8 14:35:14 Pbox kernel: [ 2497.895422] ------------[ cut here ]------------
Feb 8 14:35:14 Pbox kernel: [ 2497.895428] WARNING: at kernel/rcutree_plugin.h:442 __rcu_read_unlock+0x76/0x87()
Feb 8 14:35:14 Pbox kernel: [ 2497.895432] Hardware name: 945P-S3
Feb 8 14:35:14 Pbox kernel: [ 2497.895435] Modules linked in: ppdev lp binfmt_misc nfsd nfs nfs_acl auth_rpcgss fscache lockd sunrpc ext3 jbd ext2 loop lm90 f75375s adt7475 joydev w83781d hwmon_vid w83l785ts snd_hda_codec_realtek nouveau snd_hda_intel snd_hda_codec snd_hwdep snd_pcm mxm_wmi wmi snd_page_alloc video ttm i2c_i801 evdev drm_kms_helper
Feb 8 14:35:14 Pbox kernel: [ 2497.895508] ------------[ cut here ]------------
Feb 8 14:35:14 Pbox kernel: [ 2497.895514] WARNING: at kernel/rcutree_plugin.h:442 __rcu_read_unlock+0x76/0x87()
Feb 8 14:35:14 Pbox kernel: [ 2497.895518] Hardware name: 945P-S3
Feb 8 14:35:14 Pbox kernel: [ 2497.895521] Modules linked in: ppdev lp binfmt_misc nfsd nfs nfs_acl auth_rpcgss fscache lockd sunrpc ext3 jbd ext2 loop lm90 f75375s adt7475 joydev w83781d hwmon_vid w83l785ts snd_hda_codec_realtek nouveau snd_hda_intel snd_hda_codec snd_hwdep snd_pcm mxm_wmi wmi snd_page_alloc video ttm i2c_i801 evdev drm_kms_helper parport_pc snd_seq snd_seq_device snd_timer snd iTCO_wdt iTCO_vendor_support rng_core drm psmouse parport serio_raw i2c_algo_bit pcspkr processor soundcore i2c_core thermal_sys button ext4 crc16 jbd2 mbcache cryptd aes_x86_64 aes_generic cbc dm_crypt dm_mod usbhid hid sg sd_mod crc_t10dif ata_generic ata_piix libata scsi_mod r8169 mii uhci_hcd ehci_hcd usbcore usb_common [last unloaded: scsi_wait_scan]
Feb 8 14:35:14 Pbox kernel: [ 2497.895658] Pid: 29267, comm: java Not tainted 3.2.66-grsec-mempo.deskmaxdbg.0.2.106 #1
Feb 8 14:35:14 Pbox kernel: [ 2497.895662] Call Trace:
Feb 8 14:35:14 Pbox kernel: [ 2497.895664] <IRQ> [<ffffffff8104dfb6>] warn_slowpath_common+0x7e/0x9d
Feb 8 14:35:14 Pbox kernel: [ 2497.895675] [<ffffffff8104dffc>] warn_slowpath_null+0x27/0x2f
Feb 8 14:35:14 Pbox kernel: [ 2497.895680] [<ffffffff810b8489>] __rcu_read_unlock+0x76/0x87
Feb 8 14:35:14 Pbox kernel: [ 2497.895687] [<ffffffff81038d8f>] rcu_read_unlock+0x21/0x29
Feb 8 14:35:14 Pbox kernel: [ 2497.895693] [<ffffffff8103c977>] cpuacct_charge+0x50/0x5f
Feb 8 14:35:14 Pbox kernel: [ 2497.895699] [<ffffffff810455bc>] update_curr+0x113/0x14e
Feb 8 14:35:14 Pbox kernel: [ 2497.895705] [<ffffffff810461b7>] enqueue_task_fair+0x53/0x418
Feb 8 14:35:14 Pbox kernel: [ 2497.895710] [<ffffffff810b8489>] ? __rcu_read_unlock+0x76/0x87
Feb 8 14:35:14 Pbox kernel: [ 2497.895716] [<ffffffff8103e7f8>] enqueue_task+0x6a/0x77
Feb 8 14:35:14 Pbox kernel: [ 2497.895721] [<ffffffff8103e843>] activate_task+0x3e/0x46
Feb 8 14:35:14 Pbox kernel: [ 2497.895727] [<ffffffff8104771f>] ttwu_do_activate.constprop.175+0x2e/0x69
Feb 8 14:35:14 Pbox kernel: [ 2497.895732] [<ffffffff81047a1c>] sched_ttwu_pending+0x45/0x5d
Feb 8 14:35:14 Pbox kernel: [ 2497.895738] [<ffffffff810482b4>] scheduler_ipi+0x33/0x8a
Feb 8 14:35:14 Pbox kernel: [ 2497.895745] [<ffffffff8101e2d8>] smp_reschedule_interrupt+0x16/0x1e
Feb 8 14:35:14 Pbox kernel: [ 2497.895751] [<ffffffff8143b9c9>] reschedule_interrupt+0x89/0x90
Feb 8 14:35:14 Pbox kernel: [ 2497.895754] <EOI> [<ffffffff8104e0f2>] ? arch_local_irq_restore+0x6/0x13
Feb 8 14:35:14 Pbox kernel: [ 2497.895765] [<ffffffff8104f043>] vprintk+0x4a8/0x50d
Feb 8 14:35:14 Pbox kernel: [ 2497.895777] [<ffffffff810b8489>] ? __rcu_read_unlock+0x76/0x87
Feb 8 14:35:14 Pbox kernel: [ 2497.895783] [<ffffffff81428d13>] printk+0x44/0x4c
Feb 8 14:35:14 Pbox kernel: [ 2497.895791] [<ffffffff810960dd>] print_modules+0x5d/0x104
Feb 8 14:35:14 Pbox kernel: [ 2497.895798] [<ffffffff8104dfb1>] warn_slowpath_common+0x79/0x9d
Feb 8 14:35:14 Pbox kernel: [ 2497.895803] [<ffffffff8104dffc>] warn_slowpath_null+0x27/0x2f
Feb 8 14:35:14 Pbox kernel: [ 2497.895809] [<ffffffff810b8489>] __rcu_read_unlock+0x76/0x87
Feb 8 14:35:14 Pbox kernel: [ 2497.895815] [<ffffffff8114ac2e>] rcu_read_unlock+0x21/0x29
Feb 8 14:35:14 Pbox kernel: [ 2497.895820] [<ffffffff8114c493>] shrink_dcache_parent+0x254/0x2a9
Feb 8 14:35:14 Pbox kernel: [ 2497.895826] [<ffffffff8119757c>] proc_flush_task+0x15a/0x1d2
Feb 8 14:35:14 Pbox kernel: [ 2497.895832] [<ffffffff810508ce>] release_task+0x89/0x3e0
Feb 8 14:35:14 Pbox kernel: [ 2497.895838] [<ffffffff814379dd>] ? sub_preempt_count+0x79/0xa1
Feb 8 14:35:14 Pbox kernel: [ 2497.895843] [<ffffffff810525f9>] do_exit+0x84e/0x91a
Feb 8 14:35:14 Pbox kernel: [ 2497.895850] [<ffffffff81052704>] sys_exit+0x19/0x19
Feb 8 14:35:14 Pbox kernel: [ 2497.895855] [<ffffffff814346ac>] system_call_fastpath+0x16/0x1b
Feb 8 14:35:14 Pbox kernel: [ 2497.895860] ---[ end trace 7f949707c1622609 ]---
Feb 8 14:35:14 Pbox kernel: [ 2497.895865] parport_pc snd_seq snd_seq_device snd_timer snd iTCO_wdt iTCO_vendor_support rng_core drm psmouse parport serio_raw i2c_algo_bit pcspkr processor soundcore i2c_core thermal_sys button ext4 crc16 jbd2 mbcache cryptd aes_x86_64 aes_generic cbc dm_crypt dm_mod usbhid hid sg sd_mod crc_t10dif ata_generic ata_piix libata scsi_mod r8169 mii uhci_hcd ehci_hcd usbcore usb_common [last unloaded: scsi_wait_scan]
Feb 8 14:35:14 Pbox kernel: [ 2497.897902] Pid: 29267, comm: java Tainted: G W 3.2.66-grsec-mempo.deskmaxdbg.0.2.106 #1
Feb 8 14:35:14 Pbox kernel: [ 2497.897909] Call Trace:
Feb 8 14:35:14 Pbox kernel: [ 2497.897924] [<ffffffff8104dfb6>] warn_slowpath_common+0x7e/0x9d
Feb 8 14:35:14 Pbox kernel: [ 2497.897934] [<ffffffff8104dffc>] warn_slowpath_null+0x27/0x2f
Feb 8 14:35:14 Pbox kernel: [ 2497.897944] [<ffffffff810b8489>] __rcu_read_unlock+0x76/0x87
Feb 8 14:35:14 Pbox kernel: [ 2497.897954] [<ffffffff8114ac2e>] rcu_read_unlock+0x21/0x29
Feb 8 14:35:14 Pbox kernel: [ 2497.897962] [<ffffffff8114c493>] shrink_dcache_parent+0x254/0x2a9
Feb 8 14:35:14 Pbox kernel: [ 2497.897972] [<ffffffff8119757c>] proc_flush_task+0x15a/0x1d2
Feb 8 14:35:14 Pbox kernel: [ 2497.897982] [<ffffffff810508ce>] release_task+0x89/0x3e0
Feb 8 14:35:14 Pbox kernel: [ 2497.897990] [<ffffffff814379dd>] ? sub_preempt_count+0x79/0xa1
Feb 8 14:35:14 Pbox kernel: [ 2497.898000] [<ffffffff810525f9>] do_exit+0x84e/0x91a
Feb 8 14:35:14 Pbox kernel: [ 2497.898031] [<ffffffff81052704>] sys_exit+0x19/0x19
Feb 8 14:35:14 Pbox kernel: [ 2497.898041] [<ffffffff814346ac>] system_call_fastpath+0x16/0x1b
Feb 8 14:35:14 Pbox kernel: [ 2497.898048] ---[ end trace 7f949707c162260a ]---

[rfree]

And another trace, from KVM VM (debian, servmaxdbg), on debian servmaxdbg host.

Addresses resolved.




[ 0.000000] hard-irq read-recursion/321: ok |
[ 0.000000] soft-irq read-recursion/321: ok |
[ 0.000000] -------------------------------------------------------
[ 0.000000] Good, all 218 testcases passed! |
[ 0.000000] ---------------------------------
[ 0.000000] allocated 16777216 bytes of page_cgroup
[ 0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups
[ 0.000000] ODEBUG: 25 of 25 active objects replaced
[ 0.000000] ODEBUG: selftest passed
[ 0.000000] hpet clockevent registered
[ 0.000000] Detected 2305.790 MHz processor.
[ 0.000000] Marking TSC unstable due to TSCs unsynchronized
[ 0.004999] Calibrating delay loop (skipped) preset value.. 4611.58 BogoMIPS (lpj=2305790)
[ 0.006025] pid_max: default: 32768 minimum: 501
[ 0.012638] Security Framework initialized
[ 0.013040] AppArmor: AppArmor disabled by boot time parameter

...

[ 23.478205] input: PC Speaker as /devices/platform/pcspkr/input/input2
[ 23.646519] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0xb100, revision 0
[ 23.660179] parport_pc 00:05: reported by Plug and Play ACPI
[ 23.672173] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE]
[ 23.922256] grsec: time set by /sbin/hwclock[hwclock:421] uid/euid:0/0 gid/egid:0/0, parent /lib/udev/hwclock-set[hwclock-set:414] uid/euid:0/0 gid/egid:0/0
[ 24.469214] Error: Driver 'pcspkr' is already registered, aborting...
[ 24.828306] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
[ 30.468684]
[ 30.469534] =====================================
[ 30.469534] [ BUG: bad unlock balance detected! ]
[ 30.469534] -------------------------------------
[ 30.469534] udevd/325 is trying to release lock (rcu_read_lock) at:
[ 30.469534] ffffffff8114d8e5 ffffffff8114d8e5 = /include/trace/events/writeback.h:252
[ 30.469534] but there are no more locks to release!
[ 30.469534]
[ 30.469534] other info that might help us debug this:
[ 30.469534] no locks held by udevd/325.
[ 30.469534]
[ 30.469534] stack backtrace:
[ 30.469534] Pid: 325, comm: udevd Not tainted 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 30.469534] Call Trace:
[ 30.469534] ffffffff8114d8e5 ? d_find_alias+0x5a/0x5a = /include/trace/events/writeback.h:252
[ 30.469534] ffffffff8108643d print_unlock_inbalance_bug+0xdf/0xef = /kernel/uid16.c:229
[ 30.469534] ffffffff8114d8e5 ? d_find_alias+0x5a/0x5a = /include/trace/events/writeback.h:252
[ 30.469534] ffffffff810898e8 lock_release+0x11c/0x26e = /arch/x86/include/asm/thread_info.h:183
[ 30.469534] ffffffff8114d901 rcu_read_unlock+0x1c/0x29 = /include/trace/events/writeback.h:252
[ 30.469534] ffffffff8114f27b shrink_dcache_parent+0x267/0x2bc = /fs/fs-writeback.c:1238
[ 30.469534] ffffffff8119a7ab proc_flush_task+0xa9/0x1d2 = /fs/exportfs/expfs.c:204
[ 30.469534] ffffffff8104f82a release_task+0x89/0x3e0 = /kernel/exit.c:706
[ 30.469534] ffffffff8105012b wait_consider_task+0x5aa/0xa1d = /kernel/itimer.c:140
[ 30.469534] ffffffff810506e4 do_wait+0x146/0x27e = /kernel/itimer.c:264
[ 30.469534] ffffffff810519df sys_wait4+0xaa/0xdc = /include/trace/events/irq.h:87
[ 30.469534] ffffffff8104f72b ? disallow_signal+0x7a/0x7a = /kernel/exit.c:668
[ 30.469534] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 30.581200] ------------[ cut here ]------------
[ 30.581582] ------------[ cut here ]------------
[ 30.581595] WARNING: at kernel/rcutree_plugin.h:442 __rcu_read_unlock+0x76/0x87()
[ 30.581599] Hardware name: Bochs
[ 30.581603] Modules linked in: snd_pcm snd_page_alloc snd_timer snd psmouse soundcore i2c_piix4 parport_pc serio_raw evdev parport i2c_core pcspkr processor thermal_sys button ext4 crc16 jbd2 mbcache dm_mod sg sd_mod sr_mod cdrom crc_t10dif ata_generic ata_piix libata 8139too floppy 8139cp mii scsi_mod [last unloaded: scsi_wait_scan]
[ 30.581699] Pid: 325, comm: udevd Not tainted 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 30.581704] Call Trace:
[ 30.581717] ffffffff8104ce6a warn_slowpath_common+0x7e/0x9d = /kernel/printk.c:358
[ 30.581726] ffffffff8104ceb0 warn_slowpath_null+0x27/0x2f = /kernel/printk.c:410
[ 30.581735] ffffffff810b774a __rcu_read_unlock+0x76/0x87 = /kernel/trace/trace.c:1763
[ 30.581743] ffffffff81449c45 __atomic_notifier_call_chain+0x80/0x98 = ??:0
[ 30.581751] ffffffff81449bc5 ? notifier_call_chain+0xc3/0xc3 = ??:0
[ 30.581759] ffffffff81449c88 atomic_notifier_call_chain+0x2b/0x33 = ??:0
[ 30.581770] ffffffff812daec5 notify_write+0x2e/0x3b = /drivers/char/agp/intel-gtt.c:841
[ 30.581778] ffffffff812ddca5 vt_console_print+0x1ec/0x2b8 = /drivers/gpu/vga/vgaarb.c:916
[ 30.581787] ffffffff8104d46e __call_console_drivers+0x90/0xa8 = /kernel/cpu.c:172
[ 30.581794] ffffffff8104d4eb _call_console_drivers+0x65/0x7f = /kernel/cpu.c:113
[ 30.581803] ffffffff8104d7ce console_unlock+0x136/0x23f = /include/linux/cpumask.h:159
[ 30.581811] ffffffff8104de90 vprintk+0x4a5/0x51b = /kernel/exit.c:402
[ 30.581846] ffffffff8123dbf9 ? trace_hardirqs_on_thunk+0x41/0x46 = /include/asm-generic/getorder.h:17
[ 30.581855] ffffffff810b774a ? __rcu_read_unlock+0x76/0x87 = /kernel/trace/trace.c:1763
[ 30.581864] ffffffff81439f07 printk+0x44/0x4c = ??:0
[ 30.581873] ffffffff810b774a ? __rcu_read_unlock+0x76/0x87 = /kernel/trace/trace.c:1763
[ 30.581902] ffffffff8127fe24 ? vgacon_set_palette+0x55/0x55 = /drivers/acpi/acpica/dswexec.c:412
[ 30.581909] ffffffff8104ce18 warn_slowpath_common+0x2c/0x9d = /kernel/printk.c:459
[ 30.581916] ffffffff8127fe24 ? vgacon_set_palette+0x55/0x55 = /drivers/acpi/acpica/dswexec.c:412
[ 30.581924] ffffffff8104ceb0 warn_slowpath_null+0x27/0x2f = /kernel/printk.c:410
[ 30.581930] ffffffff810b774a __rcu_read_unlock+0x76/0x87 = /kernel/trace/trace.c:1763
[ 30.581939] ffffffff8114d906 rcu_read_unlock+0x21/0x29 = /include/linux/ftrace_event.h:301
[ 30.581946] ffffffff8114f27b shrink_dcache_parent+0x267/0x2bc = /fs/fs-writeback.c:1238
[ 30.581954] ffffffff8119a7ab proc_flush_task+0xa9/0x1d2 = /fs/exportfs/expfs.c:204
[ 30.581964] ffffffff8104f82a release_task+0x89/0x3e0 = /kernel/exit.c:706
[ 30.581970] ffffffff8105012b wait_consider_task+0x5aa/0xa1d = /kernel/itimer.c:140
[ 30.581979] ffffffff810506e4 do_wait+0x146/0x27e = /kernel/itimer.c:264
[ 30.581988] ffffffff810519df sys_wait4+0xaa/0xdc = /include/trace/events/irq.h:87
[ 30.581996] ffffffff8104f72b ? disallow_signal+0x7a/0x7a = /kernel/exit.c:668
[ 30.582041] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 30.582050] ---[ end trace c96d8629041f998b ]---
[ 30.697573] grsec: mount of tmpfs to /run/shm by /bin/mount[mount:555] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountdevsubfs.sh[mountdevsubfs.s:477] uid/euid:0/0 gid/egid:0/0
[ 30.845634] WARNING: at kernel/rcutree_plugin.h:442 __rcu_read_unlock+0x76/0x87()
[ 30.852432] Hardware name: Bochs
[ 30.855770] Modules linked in: snd_pcm snd_page_alloc snd_timer snd psmouse soundcore i2c_piix4 parport_pc serio_raw evdev parport i2c_core pcspkr processor thermal_sys button ext4 crc16 jbd2 mbcache dm_mod sg sd_mod sr_mod cdrom crc_t10dif ata_generic ata_piix libata 8139too floppy 8139cp mii scsi_mod [last unloaded: scsi_wait_scan]
[ 30.910890] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 30.915487] Call Trace:
[ 30.918050] ffffffff8104ce6a warn_slowpath_common+0x7e/0x9d = /kernel/printk.c:358
[ 30.920516] ffffffff8127fe24 ? vgacon_set_palette+0x55/0x55 = /drivers/acpi/acpica/dswexec.c:412
[ 30.925922] ffffffff8104ceb0 warn_slowpath_null+0x27/0x2f = /kernel/printk.c:410
[ 30.931005] ffffffff810b774a __rcu_read_unlock+0x76/0x87 = /kernel/trace/trace.c:1763
[ 30.934324] ffffffff8114d906 rcu_read_unlock+0x21/0x29 = /include/linux/ftrace_event.h:301
[ 30.937449] ffffffff8114f27b shrink_dcache_parent+0x267/0x2bc = /fs/fs-writeback.c:1238
[ 30.940045] ffffffff8119a7ab proc_flush_task+0xa9/0x1d2 = /fs/exportfs/expfs.c:204
[ 30.943157] ffffffff8104f82a release_task+0x89/0x3e0 = /kernel/exit.c:706
[ 30.945721] ffffffff8105012b wait_consider_task+0x5aa/0xa1d = /kernel/itimer.c:140
[ 30.948493] ffffffff810506e4 do_wait+0x146/0x27e = /kernel/itimer.c:264
[ 30.951646] ffffffff810519df sys_wait4+0xaa/0xdc = /include/trace/events/irq.h:87
[ 30.956676] ffffffff8104f72b ? disallow_signal+0x7a/0x7a = /kernel/exit.c:668
[ 30.959158] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 30.965046] ---[ end trace c96d8629041f998c ]---
[ 30.969446] BUG: sleeping function called from invalid context at fs/inode.c:420
[ 30.973941] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 30.979004] INFO: lockdep is turned off.
[ 30.981751] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 30.992507] Call Trace:
[ 30.994467] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 30.998893] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 31.007090] ffffffff811521ad end_writeback+0x24/0xb6 = /fs/splice.c:248
[ 31.010411] ffffffff81194fac proc_evict_inode+0x1d/0xa9 = /fs/sysfs/dir.c:599
[ 31.015197] ffffffff811522dc evict+0x9d/0x156 = /fs/splice.c:1637
[ 31.021501] ffffffff81152529 iput+0x194/0x1a3 = /fs/splice.c:1478
[ 31.025244] ffffffff8114ec8c dentry_kill+0x142/0x16a = /fs/fs-writeback.c:261
[ 31.029193] ffffffff8114ed3c shrink_dentry_list+0x88/0xf0 = /fs/fs-writeback.c:288
[ 31.034229] ffffffff8114f059 shrink_dcache_parent+0x45/0x2bc = /fs/fs-writeback.c:672
[ 31.051094] ffffffff8119a7ab proc_flush_task+0xa9/0x1d2 = /fs/exportfs/expfs.c:204
[ 31.053767] ffffffff8104f82a release_task+0x89/0x3e0 = /kernel/exit.c:706
[ 31.058139] ffffffff8105012b wait_consider_task+0x5aa/0xa1d = /kernel/itimer.c:140
[ 31.062726] ffffffff810506e4 do_wait+0x146/0x27e = /kernel/itimer.c:264
[ 31.068688] ffffffff810519df sys_wait4+0xaa/0xdc = /include/trace/events/irq.h:87
[ 31.074239] ffffffff8104f72b ? disallow_signal+0x7a/0x7a = /kernel/exit.c:668
[ 31.096645] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 32.644250] BUG: sleeping function called from invalid context at kernel/mutex.c:270
[ 32.649381] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 32.652476] INFO: lockdep is turned off.
[ 32.658321] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 32.664511] Call Trace:
[ 32.670390] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 32.673963] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 32.680965] ffffffff81444995 mutex_lock_nested+0x20/0x41 = ??:0
[ 32.686569] ffffffff811787d3 ep_scan_ready_list+0x40/0x1a0 = /fs/binfmt_elf.c:1147
[ 32.695523] ffffffff811780db ? ep_read_events_proc+0x7d/0x7d = /fs/binfmt_elf.c:1551
[ 32.703712] ffffffff811798e6 sys_epoll_wait+0x36f/0x42a = /include/linux/slab_def.h:173
[ 32.715955] ffffffff810467b5 ? try_to_wake_up+0x1ec/0x1ec = /kernel/sched.c:6193
[ 32.730005] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 32.739530] ffffffff8123dbf9 ? trace_hardirqs_on_thunk+0x41/0x46 = /include/asm-generic/getorder.h:17
[ 32.743691] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 32.747955] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 32.754330] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 32.757959] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 34.335668] BUG: sleeping function called from invalid context at kernel/mutex.c:270
[ 34.341970] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 34.348163] INFO: lockdep is turned off.
[ 34.352078] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 34.358427] Call Trace:
[ 34.361540] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 34.366826] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 34.369496] ffffffff81444995 mutex_lock_nested+0x20/0x41 = ??:0
[ 34.373307] ffffffff811787d3 ep_scan_ready_list+0x40/0x1a0 = /fs/binfmt_elf.c:1147
[ 34.376945] ffffffff811780db ? ep_read_events_proc+0x7d/0x7d = /fs/binfmt_elf.c:1551
[ 34.382913] ffffffff811798e6 sys_epoll_wait+0x36f/0x42a = /include/linux/slab_def.h:173
[ 34.387134] ffffffff810467b5 ? try_to_wake_up+0x1ec/0x1ec = /kernel/sched.c:6193
[ 34.392663] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 35.338941] EXT4-fs (dm-0): re-mounted. Opts: (null)
[ 35.342630] grsec: mount of /dev/mapper/debian-root to / by /bin/mount[mount:636] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/checkroot.sh[checkroot.sh:615] uid/euid:0/0 gid/egid:0/0
[ 36.174707] EXT4-fs (dm-0): re-mounted. Opts: errors=remount-ro
[ 36.178974] grsec: mount of /dev/mapper/debian-root to / by /bin/mount[mount:646] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/checkroot.sh[checkroot.sh:615] uid/euid:0/0 gid/egid:0/0
[ 36.807574] BUG: sleeping function called from invalid context at kernel/mutex.c:270
[ 36.823099] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 36.827852] INFO: lockdep is turned off.
[ 36.831162] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 36.837566] Call Trace:
[ 36.839770] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 36.848184] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 36.851417] ffffffff81444995 mutex_lock_nested+0x20/0x41 = ??:0
[ 36.852750] loop: module loaded
[ 36.857151] ffffffff811787d3 ep_scan_ready_list+0x40/0x1a0 = /fs/binfmt_elf.c:1147
[ 36.860548] ffffffff811780db ? ep_read_events_proc+0x7d/0x7d = /fs/binfmt_elf.c:1551
[ 36.884763] ffffffff811798e6 sys_epoll_wait+0x36f/0x42a = /include/linux/slab_def.h:173
[ 36.884771] ffffffff810467b5 ? try_to_wake_up+0x1ec/0x1ec = /kernel/sched.c:6193
[ 36.884778] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 36.884783] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 40.182506] BUG: sleeping function called from invalid context at kernel/mutex.c:270
[ 40.196134] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 40.205103] INFO: lockdep is turned off.
[ 40.210315] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 40.218826] Call Trace:
[ 40.225052] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 40.228554] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 40.231242] ffffffff81444995 mutex_lock_nested+0x20/0x41 = ??:0
[ 40.234172] ffffffff811787d3 ep_scan_ready_list+0x40/0x1a0 = /fs/binfmt_elf.c:1147
[ 40.237592] ffffffff811780db ? ep_read_events_proc+0x7d/0x7d = /fs/binfmt_elf.c:1551
[ 40.245272] ffffffff811798e6 sys_epoll_wait+0x36f/0x42a = /include/linux/slab_def.h:173
[ 40.248550] ffffffff810467b5 ? try_to_wake_up+0x1ec/0x1ec = /kernel/sched.c:6193
[ 40.253893] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 40.257422] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 40.263266] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 40.267000] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 41.798221] grsec: mount of tmpfs to /run by /bin/mount[mount:892] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountkernfs.sh[mountkernfs.sh:826] uid/euid:0/0 gid/egid:0/0
[ 42.316231] grsec: mount of tmpfs to /run/lock by /bin/mount[mount:909] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountkernfs.sh[mountkernfs.sh:826] uid/euid:0/0 gid/egid:0/0
[ 42.614528] grsec: mount of proc to /proc by /bin/mount[mount:919] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountkernfs.sh[mountkernfs.sh:826] uid/euid:0/0 gid/egid:0/0
[ 43.159212] grsec: mount of sysfs to /sys by /bin/mount[mount:933] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountkernfs.sh[mountkernfs.sh:826] uid/euid:0/0 gid/egid:0/0
[ 45.826908] grsec: mount of tmpfs to /run/shm by /bin/mount[mount:1103] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountdevsubfs.sh[mountdevsubfs.s:1032] uid/euid:0/0 gid/egid:0/0
[ 46.024297] grsec: mount of devpts to /dev/pts by /bin/mount[mount:1117] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountdevsubfs.sh[mountdevsubfs.s:1032] uid/euid:0/0 gid/egid:0/0
[ 47.989900] BUG: sleeping function called from invalid context at kernel/mutex.c:270
[ 48.009384] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 48.009387] INFO: lockdep is turned off.
[ 48.009391] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 48.009394] Call Trace:
[ 48.009403] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 48.009410] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 48.009416] ffffffff81444995 mutex_lock_nested+0x20/0x41 = ??:0
[ 48.009422] ffffffff811787d3 ep_scan_ready_list+0x40/0x1a0 = /fs/binfmt_elf.c:1147
[ 48.009427] ffffffff811780db ? ep_read_events_proc+0x7d/0x7d = /fs/binfmt_elf.c:1551
[ 48.009431] ffffffff811798e6 sys_epoll_wait+0x36f/0x42a = /include/linux/slab_def.h:173
[ 48.009436] ffffffff810467b5 ? try_to_wake_up+0x1ec/0x1ec = /kernel/sched.c:6193
[ 48.009441] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 49.859099] BUG: sleeping function called from invalid context at kernel/mutex.c:270
[ 49.861460] in_atomic(): 0, irqs_disabled(): 0, pid: 325, name: udevd
[ 49.863201] INFO: lockdep is turned off.
[ 49.864867] Pid: 325, comm: udevd Tainted: G W 3.2.66-grsec-mempo.servmaxdbg.0.2.106 #1
[ 49.867712] Call Trace:
[ 49.872362] ffffffff8108634f ? debug_show_held_locks+0x27/0x36 = /kernel/uid16.c:195
[ 49.874230] ffffffff81038e1f __might_sleep+0x199/0x1a7 = /kernel/sched_rt.c:460
[ 49.876066] ffffffff81444995 mutex_lock_nested+0x20/0x41 = ??:0
[ 49.878108] ffffffff811787d3 ep_scan_ready_list+0x40/0x1a0 = /fs/binfmt_elf.c:1147
[ 49.880077] ffffffff811780db ? ep_read_events_proc+0x7d/0x7d = /fs/binfmt_elf.c:1551
[ 49.882128] ffffffff811798e6 sys_epoll_wait+0x36f/0x42a = /include/linux/slab_def.h:173
[ 49.882915] grsec: mount of /dev/sda1 to /boot by /bin/mount[mount:1277] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountall.sh[mountall.sh:1229] uid/euid:0/0 gid/egid:0/0
[ 49.888281] ffffffff810467b5 ? try_to_wake_up+0x1ec/0x1ec = /kernel/sched.c:6193
[ 49.889996] ffffffff814466ec system_call_fastpath+0x16/0x1b = ??:0
[ 49.891725] ffffffff81446732 ? sysret_check+0x3c/0x7b = ??:0
[ 49.914509] EXT4-fs (dm-4): mounted filesystem with ordered data mode. Opts: (null)
[ 49.917548] grsec: mount of /dev/mapper/debian-home to /home by /bin/mount[mount:1277] uid/euid:0/0 gid/egid:0/0, parent /etc/init.d/mountall.sh[mountall.sh:1229] uid/euid:0/0 gid/egid:0/0

Generated by: lines_in_dmesg.sh
See: github.com/mempo/mempo-scripts/ - look for script lines_in_dmesg.sh
See: http://www.mempo.org (or .i2p)