I think my attachments are getting scrubbed.  Script:<div><br></div><div><div>#!/bin/bash</div><div><br></div><div>export PATH="/root/feather-trace-tools/:$PATH"</div><div>export LIBLITMUSDIR="/root/liblitmus"</div>
<div>$LIBLITMUSDIR/setsched GSN-EDF</div><div>set -e</div><div><br></div><div># lets you see TRACE() output</div><div>cat /dev/litmus/log > /root/traces/litmus_log &</div><div><br></div><div># you need to put your plugin name here</div>
<div>#/home/jerickso/litmus/liblitmus2010/setsched EDF-SS</div><div><br></div><div># start a bunch of RTSPIN instances</div><div>$LIBLITMUSDIR/rtspin -w 5 10 100 &</div><div>sleep 1</div><div>$LIBLITMUSDIR/rtspin -w 5 10 100 &</div>
<div>sleep 1</div><div>$LIBLITMUSDIR/rtspin -w 18 20 100 &</div><div>sleep 1</div><div><br></div><div># release the task system</div><div>(sleep 3 && $LIBLITMUSDIR/release_ts) &</div><div><br></div><div># start tracing, assumes your trace nodes are specified correctly</div>
<div># the in st_trace wrapper script</div><div>st_trace test</div><div><br></div><div># at this point, st_trace is running until you control+D it</div><div><br></div><div># at this point, st_trace has ended</div><div><br>
</div><div># put the location where you want your traces moved to here</div><div>mv *.bin /root/traces/</div><div><br></div><div># kill the other things we've started in the background</div><div>killall cat</div><div>
killall rtspin</div><div><br></div><div><br></div><div><br></div><div>Stack trace:</div><div><br></div><div><div>[   98.878799] ------------[ cut here ]------------</div><div>[   98.879011] kernel BUG at kernel/../litmus/sched_litmus.c:12!</div>
<div>[   98.879011] invalid opcode: 0000 [#1] PREEMPT SMP </div><div>[   98.879011] CPU 0 </div><div>[   98.879011] Pid: 1399, comm: rtspin Not tainted 3.0.0-litmuslitmus-3.0+ #46  </div><div>[   98.879011] RIP: 0010:[<ffffffff81024bd8>]  [<ffffffff81024bd8>] update_time_litmus.isra.118+0x48/0x50</div>
<div>[   98.879011] RSP: 0000:ffff880074b3bdf8  EFLAGS: 00010013</div><div>[   98.879011] RAX: 0000001705a180d5 RBX: ffff880074be3dc0 RCX: 000000170596b8e9</div><div>[   98.879011] RDX: ffff88007917ef60 RSI: ffff880074be3dc0 RDI: ffff88007cc17430</div>
<div>[   98.879011] RBP: ffff880074b3bdf8 R08: ffffffffffcc000d R09: 0000000000000001</div><div>[   98.879011] R10: 0000000000000000 R11: 000000000000000d R12: ffff880074be4040</div><div>[   98.879011] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000</div>
<div>[   98.879011] FS:  00007fb003f14720(0000) GS:ffff88007cc00000(0000) knlGS:0000000000000000</div><div>[   98.879011] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033</div><div>[   98.879011] CR2: 00007f58ce648000 CR3: 000000007918e000 CR4: 00000000000006b0</div>
<div>[   98.879011] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000</div><div>[   98.879011] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400</div><div>[   98.879011] Process rtspin (pid: 1399, threadinfo ffff880074b3a000, task ffff880074be3dc0)</div>
<div>[   98.879011] Stack:</div><div>[   98.879011]  ffff880074b3be10 ffffffff81024bf4 ffff88007cc16c00 ffff880074b3bf70</div><div>[   98.879011]  ffffffff8142a16d 0000000000000000 ffff880000000004 ffffffff815642b7</div><div>
[   98.879011]  ffff880000000004 ffffffff815642b7 ffff880074be4340 ffffffff8142d98d</div><div>[   98.879011] Call Trace:</div><div>[   98.879011]  [<ffffffff81024bf4>] pre_schedule_litmus+0x14/0x30</div><div>[   98.879011]  [<ffffffff8142a16d>] schedule+0x26d/0xcf0</div>
<div>[   98.879011]  [<ffffffff8142d98d>] ? _raw_spin_unlock_irqrestore+0x3d/0x80</div><div>[   98.879011]  [<ffffffff81099bee>] ? might_fault+0x4e/0xa0</div><div>[   98.879011]  [<ffffffff8142e501>] ? retint_careful+0xb/0x2e</div>
<div>[   98.879011]  [<ffffffff8105eecd>] ? trace_hardirqs_on_caller+0x13d/0x180</div><div>[   98.879011]  [<ffffffff8122810e>] ? trace_hardirqs_on_thunk+0x3a/0x3f</div><div>[   98.879011]  [<ffffffff8142e508>] retint_careful+0x12/0x2e</div>
<div>[   98.879011] Code: ff 75 28 48 29 c8 ba 00 00 00 00 5d 48 0f 48 c2 48 01 86 d8 0e 00 00 48 01 86 90 00 00 00 48 8b 07 48 89 86 88 00 00 00 c3 0f 0b <0f> 0b 66 0f 1f 44 00 00 55 48 81 c7 30 08 00 00 48 89 e5 53 48 </div>
<div>[   98.879011] RIP  [<ffffffff81024bd8>] update_time_litmus.isra.118+0x48/0x50</div><div>[   98.879011]  RSP <ffff880074b3bdf8></div><div>[   98.879011] ---[ end trace 83cb1420d7776445 ]---</div><div>[   98.879011] note: rtspin[1399] exited with preempt_count 2</div>
<div>[   98.879011] BUG: sleeping function called from invalid context at kernel/rwsem.c:21</div><div>[   98.879011] in_atomic(): 1, irqs_disabled(): 1, pid: 1399, name: rtspin</div><div>[   98.879011] INFO: lockdep is turned off.</div>
<div>[   98.879011] irq event stamp: 4196</div><div>[   98.879011] hardirqs last  enabled at (4195): [<ffffffff8106eaa2>] rcu_note_context_switch+0xa2/0x230</div><div>[   98.879011] hardirqs last disabled at (4196): [<ffffffff8142d862>] _raw_spin_lock_irq+0x12/0x50</div>
<div>[   98.879011] softirqs last  enabled at (4072): [<ffffffff81035940>] __do_softirq+0x100/0x150</div><div>[   98.879011] softirqs last disabled at (4055): [<ffffffff8142facc>] call_softirq+0x1c/0x26</div><div>
[   98.879011] Pid: 1399, comm: rtspin Tainted: G      D     3.0.0-litmuslitmus-3.0+ #46</div><div>[   98.879011] Call Trace:</div><div>[   98.879011]  [<ffffffff8105c720>] ? print_irqtrace_events+0xd0/0xe0</div><div>
[   98.879011]  [<ffffffff8102ca3d>] __might_sleep+0xed/0x120</div><div>[   98.879011]  [<ffffffff8142cccf>] down_read+0x1f/0x60</div><div>[   98.879011]  [<ffffffff81067ec6>] acct_collect+0x46/0x1b0</div>
<div>[   98.879011]  [<ffffffff81033a40>] do_exit+0x5d0/0x7b0</div><div>[   98.879011]  [<ffffffff810317d1>] ? kmsg_dump+0xf1/0x120</div><div>[   98.879011]  [<ffffffff810050b6>] oops_end+0x76/0xb0</div>
<div>[   98.879011]  [<ffffffff81005233>] die+0x53/0x80</div><div>[   98.879011]  [<ffffffff81001fd4>] do_trap+0xc4/0x170</div><div>[   98.879011]  [<ffffffff810022b0>] do_invalid_op+0x90/0xb0</div><div>
[   98.879011]  [<ffffffff81024bd8>] ? update_time_litmus.isra.118+0x48/0x50</div><div>[   98.879011]  [<ffffffff8122814d>] ? trace_hardirqs_off_thunk+0x3a/0x3c</div><div>[   98.879011]  [<ffffffff8142e4f4>] ? restore_args+0x30/0x30</div>
<div>[   98.879011]  [<ffffffff8142f855>] invalid_op+0x15/0x20</div><div>[   98.879011]  [<ffffffff81024bd8>] ? update_time_litmus.isra.118+0x48/0x50</div><div>[   98.879011]  [<ffffffff8142a083>] ? schedule+0x183/0xcf0</div>
<div>[   98.879011]  [<ffffffff81024bf4>] pre_schedule_litmus+0x14/0x30</div><div>[   98.879011]  [<ffffffff8142a16d>] schedule+0x26d/0xcf0</div><div>[   98.879011]  [<ffffffff8142d98d>] ? _raw_spin_unlock_irqrestore+0x3d/0x80</div>
<div>[   98.879011]  [<ffffffff81099bee>] ? might_fault+0x4e/0xa0</div><div>[   98.879011]  [<ffffffff8142e501>] ? retint_careful+0xb/0x2e</div><div>[   98.879011]  [<ffffffff8105eecd>] ? trace_hardirqs_on_caller+0x13d/0x180</div>
<div>[   98.879011]  [<ffffffff8122810e>] ? trace_hardirqs_on_thunk+0x3a/0x3f</div><div>[   98.879011]  [<ffffffff8142e508>] retint_careful+0x12/0x2e</div></div><div><br></div><div>-Jeremy Erickson</div><br><div class="gmail_quote">
On Thu, Aug 23, 2012 at 3:31 PM, Jeremy Erickson <span dir="ltr"><<a href="mailto:jerickso@cs.unc.edu" target="_blank">jerickso@cs.unc.edu</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
In a plugin I was debugging, I discovered problems caused by jobs that had not depleted their budget when put into the ready queue, but that were out of budget when taken out.  I decided to test what was happening by adding a "BUG_ON(is_queued(p));" statement to the update_time_litmus function in sched_litmus.c, which did indeed trigger for my plugin.  I think that's the source of my problems, although I'm not sure why it's happening.<div>

<br></div><div>I discovered, however, that the same BUG_ON statement is triggered in 2012.2 with the standard GSN-EDF plugin.  That seems incorrect to me - a job should only be in the release or ready queue if it is not executing, in which case it should not be consuming any budget.  Is that a bug in LITMUS^RT?  I used the attached test script and got the attached stack trace pretty consistently on KVM.</div>
<span class="HOEnZb"><font color="#888888">
<div><br></div><div>-Jeremy Erickson</div><div><br></div>
</font></span></blockquote></div><br></div>