2004-06-22 13:57:07

by kladit

[permalink] [raw]
Subject: 2.6.7-bk5 scheduling while atomic

System smp (2 x XEON, I7505) preemptive

With kernel-2.6.7-bk5 I get a lot of
"kernel: bad: scheduling while atomic!" messages
during startup.

2.6.7 runs fine using the basically the same configuration.

Did anybody else see this ?

Here is an excerpt of /var/log/messages ..

Jun 22 14:58:52 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:52 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:52 xeon2 kernel: [schedule+2000/2064] [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:58:52 xeon2 kernel: [copy_from_user+52/98] schedule+0x7d0/0x810
Jun 22 14:58:52 xeon2 kernel: [sock_sendmsg+134/204] copy_from_user+0x34/0x62
Jun 22 14:58:52 xeon2 kernel: [sys_recvmsg+415/491] sock_sendmsg+0x86/0xcc
Jun 22 14:58:52 xeon2 kernel: [sys_sched_yield+71/93] sys_sched_yield+0x47/0x5d
Jun 22 14:58:52 xeon2 kernel: sys_recvmsg+0x19f/0x1eb
Jun 22 14:58:52 xeon2 kernel: [schedule_timeout+173/175] [coredump_wait+52/149] coredump_wait+0x34/0x95
Jun 22 14:58:52 xeon2 kernel: [do_coredump+315/545] do_coredump+0x13b/0x221
Jun 22 14:58:52 xeon2 kernel: [sys_sendto+235/274] schedule_timeout+0xad/0xaf
Jun 22 14:58:52 xeon2 kernel: [get_futex_key+67/439] get_futex_key+0x43/0x1b7
Jun 22 14:58:53 xeon2 kernel: [unqueue_me+108/225] unqueue_me+0x6c/0xe1
Jun 22 14:58:53 xeon2 kernel: [futex_wait+292/393] sys_sendto+0xeb/0x112
Jun 22 14:58:53 xeon2 kernel: futex_wait+0x124/0x189
Jun 22 14:58:53 xeon2 kernel: [handle_mm_fault+413/517] handle_mm_fault+0x19d/0x205
Jun 22 14:58:53 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:53 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:53 xeon2 kernel: [do_futex+93/169] do_futex+0x5d/0xa9
Jun 22 14:58:53 xeon2 kernel: [sys_socketcall+104/582] [__dequeue_signal+223/319] __dequeue_signal+0xdf/0x13f
Jun 22 14:58:53 xeon2 kernel: [dequeue_signal+35/128] dequeue_signal+0x23/0x80
Jun 22 14:58:53 xeon2 kernel: sys_socketcall+0x68/0x246
Jun 22 14:58:53 xeon2 kernel: [sys_futex+109/247] sys_futex+0x6d/0xf7
Jun 22 14:58:53 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:53 xeon2 kernel: [get_signal_to_deliver+884/1089] get_signal_to_deliver+0x374/0x441
Jun 22 14:58:53 xeon2 kernel: [do_signal+129/325] do_signal+0x81/0x145
Jun 22 14:58:53 xeon2 kernel: [__sock_create+238/685] __sock_create+0xee/0x2ad
Jun 22 14:58:53 xeon2 kernel: [dput+147/636] dput+0x93/0x27c
Jun 22 14:58:53 xeon2 kernel: [sys_send+55/59] sys_send+0x37/0x3b
Jun 22 14:58:53 xeon2 kernel: [sys_socketcall+322/582] sys_socketcall+0x142/0x246
Jun 22 14:58:53 xeon2 kernel: [copy_to_user+50/69] copy_to_user+0x32/0x45
Jun 22 14:58:53 xeon2 kernel: [do_page_fault+0/1245] do_page_fault+0x0/0x4dd
Jun 22 14:58:53 xeon2 kernel: [do_notify_resume+55/57] do_notify_resume+0x37/0x39
Jun 22 14:58:53 xeon2 kernel: [work_notifysig+19/21] work_notifysig+0x13/0x15
Jun 22 14:58:53 xeon2 kernel: note: ntpdate[501] exited with preempt_count 3
Jun 22 14:58:53 xeon2 ntpd[504]: ntpd [email protected] Thu Feb 19 22:07:29 CET 2004 (20)
Jun 22 14:58:53 xeon2 ntpd[504]: precision = 1.000 usec
Jun 22 14:58:53 xeon2 ntpd[504]: no IPv6 interfaces found
Jun 22 14:58:53 xeon2 ntpd[504]: kernel time sync status 0040
Jun 22 14:58:53 xeon2 ntpd[504]: frequency initialized 107.116 PPM from /etc/ntp.drift
Jun 22 14:58:53 xeon2 saslauthd[523]: detach_tty : master pid is: 523
Jun 22 14:58:53 xeon2 saslauthd[523]: ipc_init : listening on socket: /var/state/saslauthd/mux
Jun 22 14:58:53 xeon2 master[530]: setrlimit: Unable to set file descriptors limit to -1: Operation not permitted
Jun 22 14:58:53 xeon2 master[530]: retrying with 1024 (current max)
Jun 22 14:58:53 xeon2 master[530]: process started
Jun 22 14:58:53 xeon2 master[532]: about to exec /usr/cyrus/bin/ctl_cyrusdb
Jun 22 14:58:54 xeon2 FaxQueuer[542]: HylaFAX (tm) Version 4.1.8
Jun 22 14:58:54 xeon2 FaxQueuer[542]: Copyright (c) 1990-1996 Sam Leffler
Jun 22 14:58:54 xeon2 FaxQueuer[542]: Copyright (c) 1991-1996 Silicon Graphics, Inc.
Jun 22 14:58:54 xeon2 HylaFAX[540]: HylaFAX INET Protocol Server: restarted.
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: [schedule+2000/2064] [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [recalc_task_prio+311/424] schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: recalc_task_prio+0x137/0x1a8
Jun 22 14:58:55 xeon2 kernel: [schedule_timeout+173/175] [sock_sendmsg+134/204] schedule_timeout+0xad/0xaf
Jun 22 14:58:55 xeon2 kernel: [get_futex_key+67/439] sock_sendmsg+0x86/0xcc
Jun 22 14:58:55 xeon2 kernel: get_futex_key+0x43/0x1b7
Jun 22 14:58:55 xeon2 kernel: [unqueue_me+108/225] unqueue_me+0x6c/0xe1
Jun 22 14:58:55 xeon2 kernel: [futex_wait+292/393] futex_wait+0x124/0x189
Jun 22 14:58:55 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:55 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:55 xeon2 kernel: [do_futex+93/169] do_futex+0x5d/0xa9
Jun 22 14:58:55 xeon2 kernel: [sys_socketcall+104/582] [sys_sched_yield+71/93] sys_sched_yield+0x47/0x5d
Jun 22 14:58:55 xeon2 kernel: sys_socketcall+0x68/0x246
Jun 22 14:58:55 xeon2 kernel: [sys_futex+109/247] sys_futex+0x6d/0xf7
Jun 22 14:58:55 xeon2 kernel: [sys_gettimeofday+44/101] sys_gettimeofday+0x2c/0x65
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: [schedule+2000/2064] [coredump_wait+52/149] coredump_wait+0x34/0x95
Jun 22 14:58:55 xeon2 kernel: schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [fbcon_cursor+726/871] [do_coredump+315/545] do_coredump+0x13b/0x221
Jun 22 14:58:55 xeon2 kernel: [sys_sendto+235/274] fbcon_cursor+0x2d6/0x367
Jun 22 14:58:55 xeon2 kernel: [__lock_sock+129/181] sys_sendto+0xeb/0x112
Jun 22 14:58:55 xeon2 kernel: [__dequeue_signal+223/319] __dequeue_signal+0xdf/0x13f
Jun 22 14:58:55 xeon2 kernel: __lock_sock+0x81/0xb5
Jun 22 14:58:55 xeon2 kernel: [autoremove_wake_function+0/67] autoremove_wake_function+0x0/0x43
Jun 22 14:58:55 xeon2 kernel: [scsi_proc_hostdir_rm+21/108] [dequeue_signal+35/128] dequeue_signal+0x23/0x80
Jun 22 14:58:55 xeon2 kernel: scsi_proc_hostdir_rm+0x15/0x6c
Jun 22 14:58:55 xeon2 kernel: [autoremove_wake_function+0/67] autoremove_wake_function+0x0/0x43
Jun 22 14:58:55 xeon2 kernel: [lock_sock+91/100] [get_signal_to_deliver+884/1089] get_signal_to_deliver+0x374/0x441
Jun 22 14:58:55 xeon2 kernel: [do_signal+129/325] do_signal+0x81/0x145
Jun 22 14:58:55 xeon2 kernel: lock_sock+0x5b/0x64
Jun 22 14:58:55 xeon2 kernel: [udp_sendmsg+630/2033] [__sock_create+238/685] udp_sendmsg+0x276/0x7f1
Jun 22 14:58:55 xeon2 kernel: [scheduler_tick+400/1285] __sock_create+0xee/0x2ad
Jun 22 14:58:55 xeon2 kernel: scheduler_tick+0x190/0x505
Jun 22 14:58:55 xeon2 kernel: [__wake_up_locked+31/33] __wake_up_locked+0x1f/0x21
Jun 22 14:58:55 xeon2 kernel: [__down_failed_trylock+7/12] [dput+147/636] dput+0x93/0x27c
Jun 22 14:58:55 xeon2 kernel: [sys_send+55/59] __down_failed_trylock+0x7/0xc
Jun 22 14:58:55 xeon2 kernel: [__print_symbol+177/376] __print_symbol+0xb1/0x178
Jun 22 14:58:55 xeon2 kernel: [__print_symbol+64/376] __print_symbol+0x40/0x178
Jun 22 14:58:55 xeon2 kernel: sys_send+0x37/0x3b
Jun 22 14:58:55 xeon2 kernel: [sys_socketcall+322/582] [inet_sendmsg+74/98] sys_socketcall+0x142/0x246
Jun 22 14:58:55 xeon2 kernel: [copy_to_user+50/69] inet_sendmsg+0x4a/0x62
Jun 22 14:58:55 xeon2 kernel: [sock_sendmsg+134/204] copy_to_user+0x32/0x45
Jun 22 14:58:55 xeon2 kernel: [do_page_fault+0/1245] do_page_fault+0x0/0x4dd
Jun 22 14:58:55 xeon2 kernel: [do_notify_resume+55/57] do_notify_resume+0x37/0x39
Jun 22 14:58:55 xeon2 kernel: [work_notifysig+19/21] work_notifysig+0x13/0x15
Jun 22 14:58:55 xeon2 kernel: sock_sendmsg+0x86/0xcc
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: [kernel_text_address+43/53] kernel_text_address+0x2b/0x35
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: [copy_from_user+52/98] copy_from_user+0x34/0x62
Jun 22 14:58:55 xeon2 kernel: [copy_from_user+52/98] copy_from_user+0x34/0x62
Jun 22 14:58:55 xeon2 kernel: [verify_iovec+50/123] <6>note: fetchmail[547] exited with preempt_count 3
Jun 22 14:58:55 xeon2 kernel: verify_iovec+0x32/0x7b
Jun 22 14:58:55 xeon2 kernel: [sys_sendmsg+297/539] sys_sendmsg+0x129/0x21b
Jun 22 14:58:55 xeon2 kernel: [schedule_timeout+173/175] schedule_timeout+0xad/0xaf
Jun 22 14:58:55 xeon2 kernel: [get_futex_key+67/439] get_futex_key+0x43/0x1b7
Jun 22 14:58:55 xeon2 kernel: [unqueue_me+108/225] unqueue_me+0x6c/0xe1
Jun 22 14:58:55 xeon2 kernel: [futex_wait+311/393] futex_wait+0x137/0x189
Jun 22 14:58:55 xeon2 kernel: [find_extend_vma+29/105] find_extend_vma+0x1d/0x69
Jun 22 14:58:55 xeon2 kernel: [get_futex_key+67/439] get_futex_key+0x43/0x1b7
Jun 22 14:58:55 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:55 xeon2 kernel: [futex_wake+64/234] futex_wake+0x40/0xea
Jun 22 14:58:55 xeon2 kernel: [sys_socketcall+577/582] sys_socketcall+0x241/0x246
Jun 22 14:58:55 xeon2 kernel: [sys_futex+109/247] sys_futex+0x6d/0xf7
Jun 22 14:58:55 xeon2 kernel: [sys_gettimeofday+44/101] sys_gettimeofday+0x2c/0x65
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [verify_iovec+50/123] verify_iovec+0x32/0x7b
Jun 22 14:58:55 xeon2 kernel: [sys_sendmsg+443/539] sys_sendmsg+0x1bb/0x21b
Jun 22 14:58:55 xeon2 kernel: [schedule_timeout+173/175] schedule_timeout+0xad/0xaf
Jun 22 14:58:55 xeon2 kernel: [get_futex_key+67/439] get_futex_key+0x43/0x1b7
Jun 22 14:58:55 xeon2 kernel: [unqueue_me+108/225] unqueue_me+0x6c/0xe1
Jun 22 14:58:55 xeon2 kernel: [futex_wait+292/393] futex_wait+0x124/0x189
Jun 22 14:58:55 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:55 xeon2 kernel: [default_wake_function+0/12] default_wake_function+0x0/0xc
Jun 22 14:58:55 xeon2 kernel: [do_futex+93/169] do_futex+0x5d/0xa9
Jun 22 14:58:55 xeon2 kernel: [sys_socketcall+577/582] sys_socketcall+0x241/0x246
Jun 22 14:58:55 xeon2 kernel: [sys_futex+109/247] sys_futex+0x6d/0xf7
Jun 22 14:58:55 xeon2 kernel: [sys_gettimeofday+44/101] sys_gettimeofday+0x2c/0x65
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: note: named[456] exited with preempt_count 3
Jun 22 14:58:55 xeon2 sshd[556]: Server listening on 0.0.0.0 port 22.
Jun 22 14:58:55 xeon2 rpc.statd[565]: Version 1.0.6 Starting
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: [schedule+2000/2064] [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [__alloc_pages+148/702] __alloc_pages+0x94/0x2be
Jun 22 14:58:55 xeon2 kernel: schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [__alloc_pages+148/702] __alloc_pages+0x94/0x2be
Jun 22 14:58:55 xeon2 kernel: [schedule_timeout+98/175] [schedule_timeout+173/175] schedule_timeout+0x62/0xaf
Jun 22 14:58:55 xeon2 kernel: [datagram_poll+254/259] schedule_timeout+0xad/0xaf
Jun 22 14:58:55 xeon2 kernel: [sock_poll+18/20] datagram_poll+0xfe/0x103
Jun 22 14:58:55 xeon2 kernel: [process_timeout+0/5] process_timeout+0x0/0x5
Jun 22 14:58:55 xeon2 kernel: sock_poll+0x12/0x14
Jun 22 14:58:55 xeon2 kernel: [do_pollfd+74/127] do_pollfd+0x4a/0x7f
Jun 22 14:58:55 xeon2 kernel: [do_poll+152/183] do_poll+0x98/0xb7
Jun 22 14:58:55 xeon2 kernel: [sys_poll+418/558] sys_poll+0x1a2/0x22e
Jun 22 14:58:55 xeon2 kernel: [__pollwait+0/193] __pollwait+0x0/0xc1
Jun 22 14:58:55 xeon2 kernel: [filp_close+72/138] filp_close+0x48/0x8a
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: [do_poll+152/183] do_poll+0x98/0xb7
Jun 22 14:58:55 xeon2 kernel: [sys_poll+418/558] sys_poll+0x1a2/0x22e
Jun 22 14:58:55 xeon2 kernel: [__pollwait+0/193] __pollwait+0x0/0xc1
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [as_can_anticipate+22/32] as_can_anticipate+0x16/0x20
Jun 22 14:58:55 xeon2 kernel: [as_dispatch_request+510/749] as_dispatch_request+0x1fe/0x2ed
Jun 22 14:58:55 xeon2 kernel: [memcpy_toiovec+39/76] memcpy_toiovec+0x27/0x4c
Jun 22 14:58:55 xeon2 kernel: [as_next_request+44/53] as_next_request+0x2c/0x35
Jun 22 14:58:55 xeon2 kernel: [elv_next_request+40/242] elv_next_request+0x28/0xf2
Jun 22 14:58:55 xeon2 kernel: [blk_remove_plug+48/103] blk_remove_plug+0x30/0x67
Jun 22 14:58:55 xeon2 kernel: [io_schedule+38/48] io_schedule+0x26/0x30
Jun 22 14:58:55 xeon2 kernel: [__lock_page+234/236] __lock_page+0xea/0xec
Jun 22 14:58:55 xeon2 kernel: [page_wake_function+0/78] page_wake_function+0x0/0x4e
Jun 22 14:58:55 xeon2 kernel: [page_wake_function+0/78] page_wake_function+0x0/0x4e
Jun 22 14:58:55 xeon2 kernel: [find_get_page+46/96] find_get_page+0x2e/0x60
Jun 22 14:58:55 xeon2 kernel: [do_generic_mapping_read+1066/1255] do_generic_mapping_read+0x42a/0x4e7
Jun 22 14:58:55 xeon2 kernel: [__generic_file_aio_read+430/537] __generic_file_aio_read+0x1ae/0x219
Jun 22 14:58:55 xeon2 kernel: [file_read_actor+0/226] file_read_actor+0x0/0xe2
Jun 22 14:58:55 xeon2 kernel: [__find_get_block+130/178] __find_get_block+0x82/0xb2
Jun 22 14:58:55 xeon2 kernel: [generic_file_read+106/136] generic_file_read+0x6a/0x88
Jun 22 14:58:55 xeon2 kernel: [permission+100/119] permission+0x64/0x77
Jun 22 14:58:55 xeon2 kernel: [may_open+78/481] may_open+0x4e/0x1e1
Jun 22 14:58:55 xeon2 kernel: [get_empty_filp+141/235] get_empty_filp+0x8d/0xeb
Jun 22 14:58:55 xeon2 kernel: [open_namei+276/996] open_namei+0x114/0x3e4
Jun 22 14:58:55 xeon2 kernel: [dentry_open+173/572] dentry_open+0xad/0x23c
Jun 22 14:58:55 xeon2 kernel: [filp_open+64/70] filp_open+0x40/0x46
Jun 22 14:58:55 xeon2 kernel: [vfs_read+205/294] vfs_read+0xcd/0x126
Jun 22 14:58:55 xeon2 kernel: [sys_read+56/89] sys_read+0x38/0x59
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:58:55 xeon2 kernel: [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:58:55 xeon2 kernel: [as_next_request+44/53] as_next_request+0x2c/0x35
Jun 22 14:58:55 xeon2 kernel: [elv_next_request+40/242] elv_next_request+0x28/0xf2
Jun 22 14:58:55 xeon2 kernel: [scsi_request_fn+633/1175] scsi_request_fn+0x279/0x497
Jun 22 14:58:55 xeon2 kernel: [io_schedule+38/48] io_schedule+0x26/0x30
Jun 22 14:58:55 xeon2 kernel: [__wait_on_buffer+138/160] __wait_on_buffer+0x8a/0xa0
Jun 22 14:58:55 xeon2 kernel: [bh_wake_function+0/65] bh_wake_function+0x0/0x41
Jun 22 14:58:55 xeon2 kernel: [bh_wake_function+0/65] bh_wake_function+0x0/0x41
Jun 22 14:58:55 xeon2 kernel: [ext2_update_inode+491/956] ext2_update_inode+0x1eb/0x3bc
Jun 22 14:58:55 xeon2 kernel: [write_inode+68/70] write_inode+0x44/0x46
Jun 22 14:58:55 xeon2 kernel: [__sync_single_inode+318/580] __sync_single_inode+0x13e/0x244
Jun 22 14:58:55 xeon2 kernel: [sync_inode+50/106] sync_inode+0x32/0x6a
Jun 22 14:58:55 xeon2 kernel: [ext2_sync_inode+44/56] ext2_sync_inode+0x2c/0x38
Jun 22 14:58:55 xeon2 kernel: [ext2_sync_file+57/80] ext2_sync_file+0x39/0x50
Jun 22 14:58:55 xeon2 kernel: [sys_fsync+148/197] sys_fsync+0x94/0xc5
Jun 22 14:58:55 xeon2 kernel: [sysenter_past_esp+82/113] sysenter_past_esp+0x52/0x71
Jun 22 14:58:55 xeon2 kernel: note: rpc.statd[565] exited with preempt_count 3
Jun 22 14:58:56 xeon2 ctl_cyrusdb[532]: recovering cyrus databases
Jun 22 14:58:56 xeon2 ctl_cyrusdb[532]: skiplist: recovered /var/imap/mailboxes.db (2 records, 432 bytes) in 0 seconds
Jun 22 14:58:56 xeon2 ctl_cyrusdb[532]: done recovering cyrus databases
Jun 22 14:58:56 xeon2 master[530]: ready for work
Jun 22 14:58:56 xeon2 master[567]: about to exec /usr/cyrus/bin/ctl_cyrusdb
Jun 22 14:58:56 xeon2 ctl_cyrusdb[567]: checkpointing cyrus databases
Jun 22 14:58:56 xeon2 ctl_cyrusdb[567]: archiving database file: /var/imap/annotations.db
Jun 22 14:58:57 xeon2 ctl_cyrusdb[567]: archiving log file: /var/imap/db/log.0000000001
Jun 22 14:58:57 xeon2 ctl_cyrusdb[567]: archiving database file: /var/imap/mailboxes.db
Jun 22 14:58:57 xeon2 ctl_cyrusdb[567]: archiving log file: /var/imap/db/log.0000000001
Jun 22 14:58:57 xeon2 ctl_cyrusdb[567]: done checkpointing cyrus databases
Jun 22 14:58:57 xeon2 master[530]: process 567 exited, status 0
Jun 22 14:59:00 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:59:00 xeon2 kernel: [schedule+2000/2064] schedule+0x7d0/0x810
Jun 22 14:59:00 xeon2 kernel: [sock_sendmsg+134/204] sock_sendmsg+0x86/0xcc
Jun 22 14:59:00 xeon2 kernel: [buffered_rmqueue+265/519] buffered_rmqueue+0x109/0x207
Jun 22 14:59:00 xeon2 kernel: [sys_sched_yield+71/93] sys_sched_yield+0x47/0x5d
Jun 22 14:59:00 xeon2 kernel: [coredump_wait+52/149] coredump_wait+0x34/0x95
Jun 22 14:59:00 xeon2 kernel: [do_coredump+315/545] do_coredump+0x13b/0x221
Jun 22 14:59:00 xeon2 kernel: [sys_sendto+235/274] sys_sendto+0xeb/0x112
Jun 22 14:59:00 xeon2 kernel: [__dequeue_signal+223/319] __dequeue_signal+0xdf/0x13f
Jun 22 14:59:00 xeon2 kernel: [dequeue_signal+35/128] dequeue_signal+0x23/0x80
Jun 22 14:59:00 xeon2 kernel: [get_signal_to_deliver+884/1089] get_signal_to_deliver+0x374/0x441
Jun 22 14:59:00 xeon2 kernel: [do_signal+129/325] do_signal+0x81/0x145
Jun 22 14:59:00 xeon2 kernel: [__sock_create+238/685] __sock_create+0xee/0x2ad
Jun 22 14:59:00 xeon2 kernel: [dput+147/636] dput+0x93/0x27c
Jun 22 14:59:00 xeon2 kernel: [sys_send+55/59] sys_send+0x37/0x3b
Jun 22 14:59:00 xeon2 kernel: [sys_socketcall+322/582] sys_socketcall+0x142/0x246
Jun 22 14:59:00 xeon2 kernel: [copy_to_user+50/69] copy_to_user+0x32/0x45
Jun 22 14:59:00 xeon2 kernel: [do_page_fault+0/1245] do_page_fault+0x0/0x4dd
Jun 22 14:59:00 xeon2 kernel: [do_notify_resume+55/57] do_notify_resume+0x37/0x39
Jun 22 14:59:00 xeon2 kernel: [work_notifysig+19/21] work_notifysig+0x13/0x15
Jun 22 14:59:00 xeon2 kernel: note: exportfs[575] exited with preempt_count 3
Jun 22 14:59:05 xeon2 kernel: bad: scheduling while atomic!
Jun 22 14:59:05 xeon2 kernel: bad: scheduling while atomic!


-
Klaus


2004-06-22 15:07:29

by Paul Fulghum

[permalink] [raw]
Subject: Re: 2.6.7-bk5 scheduling while atomic

On Tue, 2004-06-22 at 08:55, Klaus Dittrich wrote:
> System smp (2 x XEON, I7505) preemptive
>
> With kernel-2.6.7-bk5 I get a lot of
> "kernel: bad: scheduling while atomic!" messages
> during startup.
>
> 2.6.7 runs fine using the basically the same configuration.
>
> Did anybody else see this ?

Yes, same here.
kernel-2.6.7-bk5
SMP (2 x Pentium II)

2.6.7 runs fine.

> Here is an excerpt of /var/log/messages ..

The specific messages are different in my log
but the structure is the same: floods of
scheduling while atomic messages.

--
Paul Fulghum
[email protected]


2004-06-22 17:13:34

by Christian Kujau

[permalink] [raw]
Subject: Re: 2.6.7-bk5 scheduling while atomic

Linux version 2.6.7 (evil@prinz) (gcc version 3.4.0 (Debian 20040516)) #2 Sat Jun 19 22:32:44 CEST 2004
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000ec000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 000000001fff0000 (usable)
BIOS-e820: 000000001fff0000 - 000000001fff8000 (ACPI data)
BIOS-e820: 000000001fff8000 - 0000000020000000 (ACPI NVS)
BIOS-e820: 00000000ffff0000 - 0000000100000000 (reserved)
511MB LOWMEM available.
On node 0 totalpages: 131056
DMA zone: 4096 pages, LIFO batch:1
Normal zone: 126960 pages, LIFO batch:16
HighMem zone: 0 pages, LIFO batch:1
DMI 2.3 present.
ACPI disabled because your bios is from 2000 and too old
You can enable it with acpi=force
Built 1 zonelists
Kernel command line: BOOT_IMAGE=2.6-BK-old ro root=805
Local APIC disabled by BIOS -- reenabling.
Found and enabled local APIC!
Initializing CPU#0
PID hash table entries: 2048 (order 11: 16384 bytes)
Detected 902.212 MHz processor.
Using tsc for high-res timesource
Console: colour dummy device 80x25
Memory: 515816k/524224k available (2164k kernel code, 7644k reserved, 689k data, 388k init, 0k highmem)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay loop... 1777.66 BogoMIPS
Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
CPU: After generic identify, caps: 0183fbff c1c7fbff 00000000 00000000
CPU: After vendor identify, caps: 0183fbff c1c7fbff 00000000 00000000
CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
CPU: L2 Cache: 256K (64 bytes/line)
CPU: After all inits, caps: 0183fbff c1c7fbff 00000000 00000020
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
CPU: AMD Athlon(tm) Processor stepping 02
Enabling fast FPU save and restore... done.
Checking 'hlt' instruction... OK.
enabled ExtINT on CPU#0
ESR value before enabling vector: 00000000
ESR value after enabling vector: 00000000
Using local APIC timer interrupts.
calibrating APIC timer ...
..... CPU clock speed is 901.0914 MHz.
..... host bus clock speed is 200.0425 MHz.
NET: Registered protocol family 16
PCI: PCI BIOS revision 2.10 entry at 0xfdb31, last bus=1
PCI: Using configuration type 1
mtrr: v2.0 (20020519)
ACPI: Subsystem revision 20040326
ACPI: Interpreter disabled.
SCSI subsystem initialized
usbcore: registered new driver usbfs
usbcore: registered new driver hub
PCI: Probing PCI hardware
PCI: Probing PCI hardware (bus 00)
PCI: Using IRQ router VIA [1106/0686] at 0000:00:07.0
vesafb: framebuffer at 0xd0000000, mapped to 0xe0800000, size 2560k
vesafb: mode is 1280x1024x8, linelength=1280, pages=2
vesafb: protected mode interface info at c000:bbe0
vesafb: scrolling: redraw
spurious 8259A interrupt: IRQ7.
fb0: VESA VGA frame buffer device
Machine check exception polling timer started.
IA-32 Microcode Update Driver: v1.13 <[email protected]>
devfs: 2004-01-31 Richard Gooch ([email protected])
devfs: devfs_debug: 0x0
devfs: boot_options: 0x1
Initializing Cryptographic API
PCI: Disabling Via external APIC routing
Console: switching to colour frame buffer device 160x64
PCI: Found IRQ 9 for device 0000:00:0a.0
PCI: Sharing IRQ 9 with 0000:00:0e.0
3c59x: Donald Becker and others. http://www.scyld.com/network/vortex.html
0000:00:0a.0: 3Com PCI 3c905C Tornado at 0xcc00. Vers LK1.1.19
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
VP_IDE: IDE controller at PCI slot 0000:00:07.1
VP_IDE: chipset revision 16
VP_IDE: not 100% native mode: will probe irqs later
VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:07.1
ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA
ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:pio, hdd:pio
hda: IRQ probe failed (0xfffffffa)
hda: CRD-8483B, ATAPI CD/DVD-ROM drive
hdb: AOPEN CD-RW CRW3248 1.17 20020620, ATAPI CD/DVD-ROM drive
Using anticipatory io scheduler
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
PDC20265: IDE controller at PCI slot 0000:00:10.0
PCI: Found IRQ 10 for device 0000:00:10.0
PCI: Sharing IRQ 10 with 0000:00:07.3
PCI: Sharing IRQ 10 with 0000:00:07.2
PDC20265: chipset revision 2
PDC20265: ROM enabled at 0xdffe0000
PDC20265: 100% native mode on irq 10
PDC20265: (U)DMA Burst Bit ENABLED Primary PCI Mode Secondary PCI Mode.
ide2: BM-DMA at 0xb400-0xb407, BIOS settings: hde:DMA, hdf:DMA
ide3: BM-DMA at 0xb408-0xb40f, BIOS settings: hdg:pio, hdh:pio
hde: ST320413A, ATA DISK drive
ide2 at 0xbc00-0xbc07,0xb802 on irq 10
hde: max request size: 128KiB
hde: 39102336 sectors (20020 MB) w/512KiB Cache, CHS=38792/16/63, UDMA(100)
/dev/ide/host2/bus0/target0/lun0: p1 p2 p3 p4
PCI: Found IRQ 11 for device 0000:00:0c.0
sym0: <895> rev 0x1 at pci 0000:00:0c.0 irq 11
sym0: Tekram NVRAM, ID 7, Fast-40, LVD, parity checking
sym0: SCSI BUS has been reset.
scsi0 : sym-2.1.18j
sym0:0: FAST-40 WIDE SCSI 80.0 MB/s ST (25.0 ns, offset 31)
Vendor: IBM-ESXS Model: ST318305LW !# Rev: B245
Type: Direct-Access ANSI SCSI revision: 03
sym0:0:0: tagged command queuing enabled, command queue depth 16.
scsi(0:0:0:0): Beginning Domain Validation
sym0:0: asynchronous.
sym0:0: wide asynchronous.
sym0:0: FAST-40 WIDE SCSI 80.0 MB/s ST (25.0 ns, offset 31)
scsi(0:0:0:0): Ending Domain Validation
SCSI device sda: 35548320 512-byte hdwr sectors (18201 MB)
SCSI device sda: drive cache: write back
/dev/scsi/host0/bus0/target0/lun0: p1 p2 p3 < p5 p6 p7 p8 >
Attached scsi disk sda at scsi0, channel 0, id 0, lun 0
USB Universal Host Controller Interface driver v2.2
PCI: Found IRQ 10 for device 0000:00:07.2
PCI: Sharing IRQ 10 with 0000:00:07.3
PCI: Sharing IRQ 10 with 0000:00:10.0
uhci_hcd 0000:00:07.2: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller
uhci_hcd 0000:00:07.2: irq 10, io base 0000d000
uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
PCI: Found IRQ 10 for device 0000:00:07.3
PCI: Sharing IRQ 10 with 0000:00:07.2
PCI: Sharing IRQ 10 with 0000:00:10.0
uhci_hcd 0000:00:07.3: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#2)
uhci_hcd 0000:00:07.3: irq 10, io base 0000d400
uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
usbcore: registered new driver usbhid
drivers/usb/input/hid-core.c: v2.0:USB HID core driver
mice: PS/2 mouse device common for all mice
serio: i8042 AUX port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
NET: Registered protocol family 2
IP: routing cache hash table of 4096 buckets, 32Kbytes
TCP: Hash tables configured (established 32768 bind 65536)
NET: Registered protocol family 1
NET: Registered protocol family 17
PM: Reading pmdisk image.
PM: Resume from disk failed.
BIOS EDD facility v0.15 2004-May-17, 6 devices found
kjournald starting. Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
VFS: Mounted root (ext3 filesystem) readonly.
Mounted devfs on /dev
Freeing unused kernel memory: 388k freed
usb 1-1: new low speed USB device using address 2
input: USB HID v1.10 Mouse [Logitech USB-PS/2 Optical Mouse] on usb-0000:00:07.2-1
usb 1-2: new low speed USB device using address 3
input: USB HID v1.00 Keyboard [046a:0001] on usb-0000:00:07.2-2
Adding 292840k swap on /dev/sda6. Priority:0 extents:1
EXT3 FS on sda5, internal journal
Real Time Clock Driver v1.12
PCI: Found IRQ 9 for device 0000:00:0e.0
PCI: Sharing IRQ 9 with 0000:00:0a.0
nfs warning: mount version older than kernel
nfs warning: mount version older than kernel
nfs warning: mount version older than kernel
nfs warning: mount version older than kernel
nfs warning: mount version older than kernel
nfs warning: mount version older than kernel
NET: Registered protocol family 10
IPv6 over IPv4 tunneling driver
Linux agpgart interface v0.100 (c) Dave Jones
nvidia: module license 'NVIDIA' taints kernel.
0: nvidia: loading NVIDIA Linux x86 NVIDIA Kernel Module 1.0-5336 Wed Jan 14 18:29:26 PST 2004
devfs_mk_dev: could not append to parent for nvidiactl
devfs_mk_dev: could not append to parent for nvidia0
0: NVRM: AGPGART: unable to retrieve symbol table
drivers/usb/input/hid-input.c: event field not found
NTFS driver 2.1.14 [Flags: R/O DEBUG MODULE].
NTFS volume version 3.0.
hda: ATAPI 48X CD-ROM drive, 128kB Cache, DMA
Uniform CD-ROM driver Revision: 3.20
hdb: ATAPI 40X CD-ROM CD-R/RW drive, 8192kB Cache, DMA
NTFS volume version 3.0.


Attachments:
dmesg (8.56 kB)

2004-06-23 17:02:25

by Paul Fulghum

[permalink] [raw]
Subject: Re: 2.6.7-bk5 scheduling while atomic

On Tue, 2004-06-22 at 11:56, Christian Kujau wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> Klaus Dittrich wrote:
> > System smp (2 x XEON, I7505) preemptive
> >
> > With kernel-2.6.7-bk5 I get a lot of
> > "kernel: bad: scheduling while atomic!" messages
> > during startup.
> >
> > 2.6.7 runs fine using the basically the same configuration.
> >
> > Did anybody else see this ?

> yes, "me too". but i was not able to get the messages flushed to the
> disk. this is 2.6.7-BK kernel from 2004-06-21 (around 4p.m., GMT+1).

2.6.7-bk6 fixes it for me.

--
Paul Fulghum
[email protected]