2.5.13 IDE and preemptible kernel problems

Hi,

When booting an preemptible kernel 2.5.13 kernel on x86-64 I get very quickly an scheduling in interrupt BUG. It looks like the preempt_count becomes 0 inside the ATA interrupt handler. This could happen when save_flags/restore_flags and friends are unmatched and you have too many flags restores in IDE.

-Andi

No ksyms, skipping lsmod

Kernel BUG at sched.c:759
invalid operand: 0000
CPU 0 
Pid: 0, comm: swapper Not tainted
RIP: 0010:[<ffffffff80118643>]
Using defaults from ksymoops -t elf64-x86-64 -a i386:x86-64
RSP: ffffffff803688d8  EFLAGS: 00010002
RAX: 0000000000000001 RBX: ffffffff8036dfd8 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff80368a78 RDI: 0000000000000000
RBP: ffffffff80368908 R08: 000001000197fe98 R09: 000000000000000e
R10: 00000000ffffffff R11: 000000000000000a R12: ffffffff8022c6b0
R13: ffffffff80357590 R14: ffffffff8036df08 R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffffffff803649c0(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000000000000000 CR3: 0000000000101000 CR4: 00000000000006a0
Process swapper (pid: 0, stackpage=ffffffff802ece80)
Stack: ffffffff803688d8 0000000000000000 000001000197fd48 000001000197fd90 
       000001000197fd48 ffffffff80368918 ffffffff8036dfd8 ffffffff8022c6b0 
       ffffffff80357590 ffffffff80368928 
Call Trace: [<ffffffff8022c6b0>] [<ffffffff80118a9e>] [<ffffffff8022dc58>] 
       [<ffffffff8022c709>] [<ffffffff8022f0d4>] [<ffffffff80110fef>] 
       [<ffffffff80111255>] [<ffffffff8010ce60>] [<ffffffff8010ce60>] 
       [<ffffffff8010f44e>]  <EOI> [<ffffffff8010ce60>] [<ffffffff8010ce60>] 
       [<ffffffff8010f580>] [<ffffffff8010ce85>] [<ffffffff8010cf1f>] 
Code: 0f 0b 80 56 2a 80 ff ff ff ff f7 02 90 65 48 8b 04 25 08 00 

Trace; ffffffff8022c6b0 <task_no_data_intr+0/60> Trace; ffffffff80118a9e <preempt_schedule+2e/40> Trace; ffffffff8022dc58 <ide_end_drive_cmd+1d8/1f0> Trace; ffffffff8022c709 <task_no_data_intr+59/60> Trace; ffffffff8022f0d4 <ata_irq_request+f4/190> Trace; ffffffff80110fef <handle_IRQ_event+3f/80> Trace; ffffffff80111255 <do_IRQ+c5/160> Trace; ffffffff8010ce60 <default_idle+0/30> Trace; ffffffff8010ce60 <default_idle+0/30> Trace; ffffffff8010f44e <ret_from_intr+0/f> Trace; ffffffff8010f580 <retint_kernel+38/50> Trace; ffffffff8010ce85 <default_idle+25/30> Trace; ffffffff8010cf1f <cpu_idle+1f/40>

Code; ffffffff80118643 <schedule+23/450>
0000000000000000 <_RIP>:
Code; ffffffff80118643 <schedule+23/450> <=====
0: 0f 0b ud2a <=====
Code; ffffffff80118645 <schedule+25/450>
2: 80 56 2a 80 adcb $0x80,0x2a(%rsi)
Code; ffffffff80118649 <schedule+29/450>
6: ff (bad)
Code; ffffffff8011864a <schedule+2a/450>
7: ff (bad)
Code; ffffffff8011864b <schedule+2b/450>
8: ff (bad)
Code; ffffffff8011864c <schedule+2c/450>
9: ff f7 pushq %edi
Code; ffffffff8011864e <schedule+2e/450>
b: 02 90 65 48 8b 04 add 0x48b4865(%rax),%dl
Code; ffffffff80118654 <schedule+34/450>
11: 25 08 00 00 00 and $0x8,%eax

<0>Kernel panic: Aiee, killing interrupt handler!

Uz.ytkownik Andi Kleen napisa?:

Thank you for pointing out. I will re check it.

Martin, may I suggest that the next line of cleanups should be to remove all vestiges of the old global interrupt locking from the IDE driver? Including, for example, the crap "PCI method 1" access stuff in CMD640x..

Also, if you turn on spinlock debugging, that tends to help find the really silly things faster (leaving the harder races to be solved by brainforce ;)

Linus

Uz.ytkownik Linus Torvalds napisa?:

Right agreed. I forgot that this is just presumably a "workaround for borken hardware", which in fact is a long standing workarodund for driver reentrancy problems.

Naj... I could try.

Indeed... thank you for this hint.

OK, lest's make a deal you do the following and - realize immediately that there is a need for single argument time_past() or whatever and I turn spinlock debugging on :-).

[root@kozaczek linux]# find ./ -name "*.[ch]" -exec grep time_after /dev/null {} \; | wc

    265    1638   21285
[root@kozaczek linux]# find ./ -name "*.[ch]" -exec grep time_after /dev/null {} \; | grep jiffies | wc
    239    1497   19080

[root@kozaczek linux]#

Hmm.. Something like

	#define timeout_expired(x)	time_after(jiffies, (x))

migth indeed make sense.

But I'm a lazy bastard. Is there some victim^H^H^H^H^H^Hhero who would want to do the 'sed s/time_after(jiffies,/timeout_expired(/g' and verify that it does the right thing and send it to me as a patch?

The thing is, I wonder if it should be "time_after(jiffies,x)" or "time_after_eq(jiffies,x)". There's a single-tick difference there..

Linus

If you allow a lazy victim to throw in some statistics first: ;-)

299 potential users preferring time_after_eq, and 160 voting for time_after (assuming use of !timeout_expired(x), too):

linux-2.5.13> find ./ -name "*.[ch]" -exec grep "time_before(*jiffies"
/dev/null {} \; | wc -l

    248
linux-2.5.13> find ./ -name "*.[ch]" -exec grep "time_before_eq( *jiffies" 
 /dev/null {} \; | wc -l
     20
linux-2.5.13> find ./ -name "*.[ch]" -exec grep "time_after( *jiffies" 
 /dev/null {} \; | wc -l
    140
linux-2.5.13> find ./ -name "*.[ch]" -exec grep "time_after_eq( *jiffies" 
 /dev/null {} \; | wc -l
     51

That probably means we need both, as something like timeout_expired(x+1) seems to call for new "off by one" errors.

Tim

Uz.ytkownik John Weber napisa?:

Yeep. And now please take the next step and grep for "jiffies + 1"

to realize that a timeout primitive along the following

take_a_nap(temeout_function, timeout_data);

would help simpify the usage of timers and speed up the kernel due to cache locality for stuff which is added to the global timer list just for doing short micro-polls and beeing taken out ther on the next scheduler round. In esp. nearly every single eth driver out there shows precisely what I mean.

Becouse most of the timers get only added for one jiffie!

That would be good because in the longer term the elimination of random references to jiffies is pretty essential to low power devices and for things like S/390 scaling.

Alan