Bug 12393

Summary: debugging in dosemu causes lots of 'scheduling while atomic'
Product: Platform Specific/Hardware Reporter: Michal Suchanek (hramrach)
Component: i386Assignee: platform_i386
Status: CLOSED CODE_FIX    
Severity: normal CC: rjw
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.28 Subsystem:
Regression: Yes Bisected commit-id:
Bug Depends on:    
Bug Blocks: 11808    

Description Michal Suchanek 2009-01-09 07:28:36 UTC 
Latest working kernel version: none known
Earliest failing kernel version: 2.6.28-rc8
Distribution: Debian
Hardware Environment: mac mini T2300 cpu
Software Environment:  dosem 1.4.0
Problem Description: 

After stepping in freedos 'debug' utility the kernel starts to prints lots of 'scheduling while atomic; reports into the system log. It writes these messages at high rate until some subsequent operation causes dosemu to crash.

To reproduce:

1) install dosemu

2) run debug

3) use the trace command in debug
In the sample below I enter the "xor ax,ax" instruction to make sure no inherently problematic instruction is executed.


"Welcome to dosemu 1.4.0.0!"
C:\>debug
-A
07CA:0100 xor ax,ax
07CA:0102 
-t
AX=0000  BX=0000  CX=0000  DX=0000  SP=FFFE  BP=0000  SI=0000  DI=0000
DS=07CA  ES=07CA  SS=07CA  CS=07CA  IP=0102   NV UP DI PL ZR NA PE NC
07CA:0102 00FF          ADD     BH,BH
-q
Segmentation fault


Sample of the log - I have about 3 gigabytes of this.


Jan  8 15:23:43 uvt316-2 kernel: [  467.637133] Pid: 3170, comm: dosemu.bin Not tainted 2.6.28-macmini #1
Jan  8 15:23:43 uvt316-2 kernel: [  467.637136] Call Trace:
Jan  8 15:23:43 uvt316-2 kernel: [  467.637142]  [<c02c2895>] schedule+0x8f/0x705
Jan  8 15:23:43 uvt316-2 kernel: [  467.637146]  [<c01337e2>] __queue_work+0x4d/0x5a
Jan  8 15:23:43 uvt316-2 kernel: [  467.637187]  [<f8a20e81>] ata_sff_qc_issue+0x1ba/0x1d8 [libata]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637230]  [<f892650e>] scsi_done+0x0/0x8 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637272]  [<f8a19f82>] ata_scsi_translate+0xcb/0xf7 [libata]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637278]  [<c02c3027>] schedule_timeout+0x14/0xbb
Jan  8 15:23:43 uvt316-2 kernel: [  467.637321]  [<f8a1bacd>] ata_scsi_queuecmd+0x1a1/0x1a9 [libata]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637326]  [<c01ddebd>] elv_next_request+0x1aa/0x1b8
Jan  8 15:23:43 uvt316-2 kernel: [  467.637367]  [<f8926753>] scsi_dispatch_cmd+0x17c/0x1dc [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637406]  [<f892af4b>] scsi_request_fn+0x3ca/0x480 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637410]  [<c02c2745>] wait_for_common+0xca/0x12e
Jan  8 15:23:43 uvt316-2 kernel: [  467.637415]  [<c01210e9>] default_wake_function+0x0/0x8
Jan  8 15:23:43 uvt316-2 kernel: [  467.637419]  [<c01e2363>] blk_execute_rq+0x82/0x9b
Jan  8 15:23:43 uvt316-2 kernel: [  467.637435]  [<c01df99e>] get_request+0x203/0x310
Jan  8 15:23:43 uvt316-2 kernel: [  467.637439]  [<c01dff45>] get_request_wait+0x25/0x171
Jan  8 12:50:25 uvt316-2 kernel: imklog 3.18.2, log source = /proc/kmsg started.
Jan  8 12:59:49 uvt316-2 kernel: [  869.679880] BUG: scheduling while atomic: dosemu.bin/3205/0x00000001
Jan  8 12:59:49 uvt316-2 kernel: [  869.689075] Modules linked in: binfmt_misc kvm_intel kvm xt_tcpudp xt_conntrack xt_state xt_dscp xt_DSCP xt_CLASSIFY ipt_LOG ipt_REJECT xt_owner nf_nat_ftp nf_conntrack_ftp nf_nat_sip nf_conntrack_sip nf_nat_h323 nf_conntrack_h323 nf_nat_pptp nf_conntrack_pptp nf_conntrack_proto_gre nf_nat_proto_gre nf_nat_irc nf_conntrack_irc iptable_filter iptable_nat ipt_MASQUERADE nf_nat xt_multiport xt_iprange nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables tun bridge stp llc ipv6 af_packet hfsplus nls_base coretemp firewire_sbp2 loop arc4 hid_dell hid_pl hid_cypress hid_zpff hid_gyration hid_bright hid_sony hid_samsung hid_microsoft hid_tmff hid_monterey ecb hid_ezkey hid_apple hid_a4tech hid_logitech ath5k mac80211 usbhid ff_memless hid_cherry hid_sunplus hid_petalynx hid_belkin hid_chicony snd_hda_intel i2c_i801 pcspkr evdev led_class iTCO_wdt hid i2c_core snd_pcm snd_seq snd_timer snd_seq_device rng_core snd cfg80211 soundcore snd_page_alloc tpm_infineon tpm tpm_bios in
Jan  8 12:59:49 uvt316-2 kernel: tel_agp video output button agpgart ext3 jbd mbcache sg sr_mod cdrom ata_generic sd_mod crc_t10dif usb_storage ata_piix ahci firewire_ohci firewire_core crc_itu_t libata scsi_mod ehci_hcd uhci_hcd usbcore sky2 thermal processor fan thermal_sys hwmon
Jan  8 12:59:49 uvt316-2 kernel: [  869.791579] Pid: 3205, comm: dosemu.bin Not tainted 2.6.28-rc7-macmini #1
Jan  8 12:59:49 uvt316-2 kernel: [  869.802410] Call Trace:
Jan  8 12:59:49 uvt316-2 kernel: [  869.813129]  [<c02c26f5>] schedule+0x8f/0x705
Jan  8 12:59:49 uvt316-2 kernel: [  869.824103]  [<c013a96c>] getnstimeofday+0x32/0xb5
Jan  8 12:59:49 uvt316-2 kernel: [  869.835069]  [<c013a9fe>] do_gettimeofday+0xf/0x29
Jan  8 12:59:49 uvt316-2 kernel: [  869.846022]  [<c012e598>] sys_rt_sigsuspend+0xbc/0xd9
Jan  8 12:59:49 uvt316-2 kernel: [  869.856975]  [<c010398b>] sysenter_do_call+0x12/0x2f
Jan  8 12:59:49 uvt316-2 kernel: [  869.867902] BUG: scheduling while atomic: dosemu.bin/3205/0x00000001
Jan  8 12:59:49 uvt316-2 kernel: [  869.878780] Modules linked in: binfmt_misc kvm_intel kvm xt_tcpudp xt_conntrack xt_state xt_dscp xt_DSCP xt_CLASSIFY ipt_LOG ipt_REJECT xt_owner nf_nat_ftp nf_conntrack_ftp nf_nat_sip nf_conntrack_sip nf_nat_h323 nf_conntrack_h323 nf_nat_pptp nf_conntrack_pptp nf_conntrack_proto_gre nf_nat_proto_gre nf_nat_irc nf_conntrack_irc iptable_filter iptable_nat ipt_MASQUERADE nf_nat xt_multiport xt_iprange nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables tun bridge stp llc ipv6 af_packet hfsplus nls_base coretemp firewire_sbp2 loop arc4 hid_dell hid_pl hid_cypress hid_zpff hid_gyration hid_bright hid_sony hid_samsung hid_micro...skipping...
nntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables tun bridge stp llc ipv6 af_packet hfsplus nls_base co
retemp firewire_sbp2 loop hid_dell hid_pl hid_cypress hid_zpff hid_gyration hid_bright hid_sony hid_samsung hid_m
icrosoft hid_tmff hid_monterey hid_ezkey hid_apple hid_a4tech hid_logitech arc4 ecb ff_memless hid_cherry hid_sun
plus hid_petalynx evdev snd_hda_intel hid_belkin hid_chicony ath5k usbhid i2c_i801 iTCO_wdt mac80211 snd_pcm snd_
seq snd_timer snd_seq_device i2c_core pcspkr hid led_class rng_core snd soundcore snd_page_alloc cfg80211 tpm_inf
ineon tpm tp
Jan  8 15:23:43 uvt316-2 kernel: m_bios intel_agp video output agpgart button ext3 jbd mbcache sg sr_mod cdrom at
a_generic sd_mod crc_t10dif usb_storage ata_piix ahci libata scsi_mod firewire_ohci firewire_core crc_itu_t ehci_
hcd uhci_hcd usbcore sky2 thermal processor fan thermal_sys hwmon
Jan  8 15:23:43 uvt316-2 kernel: [  467.637133] Pid: 3170, comm: dosemu.bin Not tainted 2.6.28-macmini #1
Jan  8 15:23:43 uvt316-2 kernel: [  467.637136] Call Trace:
Jan  8 15:23:43 uvt316-2 kernel: [  467.637142]  [<c02c2895>] schedule+0x8f/0x705
Jan  8 15:23:43 uvt316-2 kernel: [  467.637146]  [<c01337e2>] __queue_work+0x4d/0x5a
Jan  8 15:23:43 uvt316-2 kernel: [  467.637187]  [<f8a20e81>] ata_sff_qc_issue+0x1ba/0x1d8 [libata]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637230]  [<f892650e>] scsi_done+0x0/0x8 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637272]  [<f8a19f82>] ata_scsi_translate+0xcb/0xf7 [libata]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637278]  [<c02c3027>] schedule_timeout+0x14/0xbb
Jan  8 15:23:43 uvt316-2 kernel: [  467.637321]  [<f8a1bacd>] ata_scsi_queuecmd+0x1a1/0x1a9 [libata]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637326]  [<c01ddebd>] elv_next_request+0x1aa/0x1b8
Jan  8 15:23:43 uvt316-2 kernel: [  467.637367]  [<f8926753>] scsi_dispatch_cmd+0x17c/0x1dc [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637406]  [<f892af4b>] scsi_request_fn+0x3ca/0x480 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637410]  [<c02c2745>] wait_for_common+0xca/0x12e
Jan  8 15:23:43 uvt316-2 kernel: [  467.637415]  [<c01210e9>] default_wake_function+0x0/0x8
Jan  8 15:23:43 uvt316-2 kernel: [  467.637419]  [<c01e2363>] blk_execute_rq+0x82/0x9b
Jan  8 15:23:43 uvt316-2 kernel: [  467.637422]  [<c01e2234>] blk_end_sync_rq+0x0/0x23
Jan  8 15:23:43 uvt316-2 kernel: [  467.637427]  [<c01e9027>] cfq_set_request+0x0/0x2ab
Jan  8 15:23:43 uvt316-2 kernel: [  467.637431]  [<c01dd2f7>] elv_set_request+0x14/0x22
Jan  8 15:23:43 uvt316-2 kernel: [  467.637435]  [<c01df99e>] get_request+0x203/0x310
Jan  8 15:23:43 uvt316-2 kernel: [  467.637439]  [<c01dff45>] get_request_wait+0x25/0x171
Jan  8 15:23:43 uvt316-2 kernel: [  467.637480]  [<f892c090>] scsi_execute+0xce/0x116 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637518]  [<f892c12e>] scsi_execute_req+0x56/0x7d [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637557]  [<f892757d>] ioctl_internal_command+0x48/0x123 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637604]  [<f8927699>] scsi_set_medium_removal+0x41/0x65 [scsi_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637627]  [<f89ff09e>] cdrom_release+0x157/0x1a5 [cdrom]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637632]  [<c0174563>] shmem_truncate+0xf/0x12
Jan  8 15:23:43 uvt316-2 kernel: [  467.637637]  [<c02c4428>] _spin_lock+0x5/0x7
Jan  8 15:23:43 uvt316-2 kernel: [  467.637640]  [<c0174566>] shmem_delete_inode+0x0/0xcc
Jan  8 15:23:43 uvt316-2 kernel: [  467.637658]  [<f8a3a36d>] sr_block_release+0xf/0x1a [sr_mod]
Jan  8 15:23:43 uvt316-2 kernel: [  467.637663]  [<c019741c>] __blkdev_put+0x7a/0x10f
Jan  8 15:23:43 uvt316-2 kernel: [  467.637666]  [<c017ad8f>] __fput+0xa6/0x14c
Jan  8 15:23:43 uvt316-2 kernel: [  467.637670]  [<c0178706>] filp_close+0x4d/0x53
Jan  8 15:23:43 uvt316-2 kernel: [  467.637675]  [<c01275db>] put_files_struct+0x60/0xa6
Jan  8 15:23:43 uvt316-2 kernel: [  467.637679]  [<c0128c11>] do_exit+0x1b0/0x6c7
Jan  8 15:23:43 uvt316-2 kernel: [  467.637683]  [<c0129190>] do_group_exit+0x68/0x8f
Jan  8 15:23:43 uvt316-2 kernel: [  467.637687]  [<c0130a59>] get_signal_to_deliver+0x314/0x337
Jan  8 15:23:43 uvt316-2 kernel: [  467.637691]  [<c0130388>] force_sig_info+0x95/0x9f
Jan  8 15:23:43 uvt316-2 kernel: [  467.637695]  [<c0117e7b>] do_page_fault+0x0/0x661
Jan  8 15:23:43 uvt316-2 kernel: [  467.637699]  [<c0102cab>] do_notify_resume+0x64/0x6ba
Jan  8 15:23:43 uvt316-2 kernel: [  467.637703]  [<c02c0000>] native_cpu_up+0x61c/0x664
Jan  8 15:23:43 uvt316-2 kernel: [  467.637707]  [<c0117e7b>] do_page_fault+0x0/0x661
Jan  8 15:23:43 uvt316-2 kernel: [  467.637710]  [<c0103aa0>] work_notifysig+0x13/0x1b
Jan  9 03:12:33 uvt316-2 kernel: [42998.259051] [drm:i915_wait_irq] *ERROR* EBUSY -- rec: 44615424 emitted: 44615428
Comment 1 Rafael J. Wysocki 2009-02-14 14:47:06 UTC 
Handled-By : Thomas Gleixner <tglx@linutronix.de>
Patch : http://lkml.org/lkml/2009/1/13/445
Comment 2 Rafael J. Wysocki 2009-02-25 14:48:01 UTC 
On Tuesday 24 February 2009, Thomas Gleixner wrote:
> On Mon, 23 Feb 2009, Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry   : http://bugzilla.kernel.org/show_bug.cgi?id=12393
> > Subject             : debugging in dosemu causes lots of 'scheduling while
> atomic'
> > Submitter   : Michal Suchanek <hramrach@centrum.cz>
> > Date                : 2009-01-09 07:28 (46 days old)
> > Handled-By  : Thomas Gleixner <tglx@linutronix.de>
> > Patch               : http://lkml.org/lkml/2009/1/13/445
> 
> Commit be716615fe596ee117292dc615e95f707fb67fd1 in Linus tree.
> 
> "Cc: stable@kernel.org" is in the commit log, so stable folks should
> have it as well.