Hello,
I'm a student of Computer Science. For my Master thesis I want to test
a patch that allow to use a generic scheduler, and this scheduler can
be
inserted as module. The patch and the module that I want to test is
for a bit old kernel, version 2.6.21.4. I applyed before realtime
patch and after generic scheduler
patch.
When I try to use the module in qemu everything seems to work (the
computation continue and the results are as I aspected) but I had a
sort of warning on the emulator.
In attachement I add this messages.
Otherwise when I try the module on real pc the machine hang on in a
deadlock, but sadly I don't know how the save the output of the kernel
debugger because I have no serial port
on my second pc..
If I recompile the kernel with no High Resolution Timer Support the
patch works also in the real machine.
I see that the module set an hrtimer inside a section locked by a
spinlock. Could be this a problem?
Thanks in advance
Nicoka
Could not open '/dev/kqemu' - QEMU acceleration layer not activated: No such file or directory
qemu: loading initrd (0x12fe4e bytes) at 0x7ec0000
Linux version 2.6.21.4-rt12-cfs-v17 (nico@nicodeb) (gcc version 4.1.3 20080623 (prerelease) (Debian 4.1.2-23)) #10 SMP PREEMPT RT Tue Jan 27 11:54:23 CET 2009
BIOS-provided physical RAM map:
sanitize start
sanitize end
copy_e820_map() start: 0000000000000000 size: 000000000009fc00 end: 000000000009fc00 type: 1
copy_e820_map() type is E820_RAM
copy_e820_map() start: 000000000009fc00 size: 0000000000000400 end: 00000000000a0000 type: 2
copy_e820_map() start: 00000000000e8000 size: 0000000000018000 end: 0000000000100000 type: 2
copy_e820_map() start: 0000000000100000 size: 0000000007ef0000 end: 0000000007ff0000 type: 1
copy_e820_map() type is E820_RAM
copy_e820_map() start: 0000000007ff0000 size: 0000000000010000 end: 0000000008000000 type: 3
copy_e820_map() start: 00000000fffc0000 size: 0000000000040000 end: 0000000100000000 type: 2
BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 0000000007ff0000 (usable)
BIOS-e820: 0000000007ff0000 - 0000000008000000 (ACPI data)
BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
0MB HIGHMEM available.
127MB LOWMEM available.
Zone PFN ranges:
DMA 0 -> 4096
Normal 4096 -> 32752
HighMem 32752 -> 32752
early_node_map[1] active PFN ranges
0: 0 -> 32752
DMI 2.4 present.
ACPI: RSDP 000FB8A0, 0014 (r0 QEMU )
ACPI: RSDT 07FF0000, 0030 (r1 QEMU QEMURSDT 1 QEMU 1)
ACPI: FACP 07FF0030, 0074 (r1 QEMU QEMUFACP 1 QEMU 1)
ACPI: DSDT 07FF0100, 0861 (r1 BXPC BXDSDT 1 INTL 20061109)
ACPI: FACS 07FF00C0, 0040
ACPI: APIC 07FF0998, 0040 (r1 QEMU QEMUAPIC 1 QEMU 1)
ACPI: SSDT 07FF0961, 0037 (r1 QEMU QEMUSSDT 1 QEMU 1)
ACPI: PM-Timer IO Port: 0xb008
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
Processor #0 6:3 APIC version 17
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23
Enabling APIC mode: Flat. Using 1 I/O APICs
Using ACPI (MADT) for SMP configuration information
Allocating PCI resources starting at 10000000 (gap: 08000000:f7fc0000)
Real-Time Preemption Support (C) 2004-2007 Ingo Molnar
Built 1 zonelists. Total pages: 31825
Kernel command line: console=tty0 console=ttyS0,9600
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
WARNING: experimental RCU implementation.
PID hash table entries: 512 (order: 9, 2048 bytes)
Detected 1666.816 MHz processor.
Console: colour VGA+ 80x25
Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
... MAX_LOCKDEP_SUBCLASSES: 8
... MAX_LOCK_DEPTH: 30
... MAX_LOCKDEP_KEYS: 2048
... CLASSHASH_SIZE: 1024
... MAX_LOCKDEP_ENTRIES: 16384
... MAX_LOCKDEP_CHAINS: 32768
... CHAINHASH_SIZE: 16384
memory used by lock dependency info: 1704 kB
per task-struct memory footprint: 1200 bytes
Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
Memory: 118920k/131008k available (1759k kernel code, 11696k reserved, 957k data, 224k init, 0k highmem)
virtual kernel memory layout:
fixmap : 0xfff4f000 - 0xfffff000 ( 704 kB)
pkmap : 0xff800000 - 0xffc00000 (4096 kB)
vmalloc : 0xc8800000 - 0xff7fe000 ( 879 MB)
lowmem : 0xc0000000 - 0xc7ff0000 ( 127 MB)
.init : 0xc03ad000 - 0xc03e5000 ( 224 kB)
.data : 0xc02b7f70 - 0xc03a75b4 ( 957 kB)
.text : 0xc0100000 - 0xc02b7f70 (1759 kB)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay using timer specific routine.. 3370.09 BogoMIPS (lpj=6740188)
Security Framework v1.0.0 initialized
SELinux: Disabled at boot.
Capability LSM initialized
Mount-cache hash table entries: 512
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 2048K
Checking 'hlt' instruction... OK.
SMP alternatives: switching to UP code
Freeing SMP alternatives: 9k freed
ACPI: Core revision 20070126
CPU0: Intel Pentium II (Klamath) stepping 03
Total of 1 processors activated (3370.09 BogoMIPS).
ENABLING IO-APIC IRQs
..TIMER: vector=0x31 apic1=0 pin1=0 apic2=-1 pin2=-1
Brought up 1 CPUs
Booting paravirtualized kernel on bare hardware
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: PCI BIOS revision 2.10 entry at 0xfb200, last bus=0
PCI: Using configuration type 1
Setting up standard PCI resources
ACPI: Interpreter enabled
ACPI: (supports S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
* Found PM-Timer Bug on the chipset. Due to workarounds for a bug,
* this clock source is slow. Consider trying other clock sources
PCI quirk: region b000-b03f claimed by PIIX4 ACPI
PCI quirk: region b100-b10f claimed by PIIX4 SMB
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 *11 12)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 *9 10 11 12)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11 12)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 *9 10 11 12)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
pnp: PnP ACPI: found 7 devices
PnPBIOS: Disabled by ACPI PNP
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report
PCI: Ignore bogus resource 6 [0:0] of 0000:00:02.0
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
TCP established hash table entries: 4096 (order: 6, 425984 bytes)
TCP bind hash table entries: 4096 (order: 6, 393216 bytes)
TCP: Hash tables configured (established 4096 bind 4096)
TCP reno registered
checking if image is initramfs... it is
Freeing initrd memory: 1215k freed
Initializing RT-Tester: OK
audit: initializing netlink socket (disabled)
audit(1233054206.408:1): initialized
Total HugeTLB memory allocated, 0
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
Limiting direct PCI/PCI transfers.
PCI: PIIX3: Enabling Passive Release on 0000:00:01.0
Activating ISA DMA hang workarounds.
isapnp: Scanning for PnP cards...
isapnp: No Plug & Play device found
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16450
00:06: ttyS0 at I/O 0x3f8 (irq = 4) is a 16450
RAMDISK driver initialized: 16 RAM disks of 8192K size 1024 blocksize
PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
input: AT Translated Set 2 keyboard as /class/input/input0
rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
rtc0: alarms up to one day
TCP cubic registered
NET: Registered protocol family 1
NET: Registered protocol family 17
Using IPI No-Shortcut mode
rtc_cmos 00:01: setting the system clock to 2009-01-27 11:03:28 (1233054208)
*****************************************************************************
* *
* REMINDER, the following debugging options are turned on in your .config: *
* *
* CONFIG_DEBUG_RT_MUTEXES *
* CONFIG_LOCKDEP *
* *
* they may increase runtime overhead and latencies. *
* *
*****************************************************************************
Freeing unused kernel memory: 224k freed
warning: can't open /etc/fstab: No such file or directory
mount: unknown filesystem type 'ext2'
exit
mkalltests.sh test1.sh test3.sh test5.sh
mktests-multi.sh test2.sh test4.sh test6.sh
mktests.sh test3-multi.sh test5-multi.sh
Doing only the Non-MultiTask tests
Modules directory: /lib/modules/cbs
Scheduler: cbs_sched_plain.ko
Modules directory: /lib/modules/cbs
Set tests to 1 2 3 4 5 6
Executing tests 1 2 3 4 5 6 on module cbs_sched_plain.ko
Inserting CBS Module (parameters: [])
CBS init: initing enforce timer
Init done!
Going with test1.sh
Setting scheduler (5000 200000)
Setting scheduler (1000 10000)
SetSched done!
Threshold: 169468
SetSched done!
Sleeping...
Threshold: 169468
Sleeping...
stopped custom tracer.
=======================================================
[ INFO: possible circular locking dependency detected ]
[ 2.6.21.4-rt12-cfs-v17 #10
-------------------------------------------------------
swapper/0 is trying to acquire lock:
(&rq->rq_lock_key){+...}, at: [<c0120d12>] task_rq_lock+0x45/0x6c
but task is already holding lock:
(&cpu_base->lock_key){+...}, at: [<c013cf18>] hrtimer_interrupt+0x80/0x1b8
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #1 (&cpu_base->lock_key){+...}:
[<c0143f5a>] __lock_acquire+0xa69/0xbfb
[<c013ca36>] lock_hrtimer_base+0x15/0x2f
[<c02b580a>] rt_spin_lock_slowlock+0x21/0x18d
[<c0144164>] lock_acquire+0x78/0x9c
[<c013ca36>] lock_hrtimer_base+0x15/0x2f
[<c02b68df>] __spin_lock_irqsave+0x4d/0x5c
[<c013ca36>] lock_hrtimer_base+0x15/0x2f
[<c013ca36>] lock_hrtimer_base+0x15/0x2f
[<c013cb20>] hrtimer_start+0x1a/0x106
[<c880a7be>] sched_set_timer+0x2a/0x2e [cbs_sched]
[<c011ff54>] enqueue_task+0x100/0x112
[<c011ff74>] activate_task+0xe/0x1b
[<c0121d61>] generic_sched_setscheduler+0xef/0x153
[<c012207f>] do_sched_setscheduler+0x8c/0xc0
[<c01040a0>] syscall_call+0x7/0xb
[<ffffffff>] 0xffffffff
-> #0 (&rq->rq_lock_key){+...}:
[<c0141bf0>] print_circular_bug_entry+0x40/0x46
[<c0143e46>] __lock_acquire+0x955/0xbfb
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c0144164>] lock_acquire+0x78/0x9c
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c02b65fa>] __spin_lock+0x33/0x3e
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c0122730>] try_to_wake_up+0x27/0x364
[<c013cf18>] hrtimer_interrupt+0x80/0x1b8
[<c0122b0c>] wake_up_process+0x19/0x1b
[<c013c589>] hrtimer_wakeup+0x15/0x18
[<c013cfbc>] hrtimer_interrupt+0x124/0x1b8
[<c0115eba>] smp_apic_timer_interrupt+0x6c/0x7d
[<c0102a93>] default_idle+0x0/0x73
[<c0104b91>] apic_timer_interrupt+0x29/0x38
[<c0102a93>] default_idle+0x0/0x73
[<c0104b9b>] apic_timer_interrupt+0x33/0x38
[<c0102ae0>] default_idle+0x4d/0x73
[<c0102a93>] default_idle+0x0/0x73
[<c011bb2f>] native_safe_halt+0x2/0x3
[<c0102ae6>] default_idle+0x53/0x73
[<c01023d9>] cpu_idle+0xc5/0x121
[<c03adc71>] start_kernel+0x4ee/0x4f6
[<c03ad1b8>] unknown_bootoption+0x0/0x202
[<ffffffff>] 0xffffffff
other info that might help us debug this:
1 lock held by swapper/0:
#0: (&cpu_base->lock_key){+...}, at: [<c013cf18>] hrtimer_interrupt+0x80/0x1b8
stack backtrace:
[<c01425cb>] print_circular_bug_tail+0x5f/0x67
[<c0141bf0>] print_circular_bug_entry+0x40/0x46
[<c0143e46>] __lock_acquire+0x955/0xbfb
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c0144164>] lock_acquire+0x78/0x9c
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c02b65fa>] __spin_lock+0x33/0x3e
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c0120d12>] task_rq_lock+0x45/0x6c
[<c0122730>] try_to_wake_up+0x27/0x364
[<c013cf18>] hrtimer_interrupt+0x80/0x1b8
[<c0122b0c>] wake_up_process+0x19/0x1b
[<c013c589>] hrtimer_wakeup+0x15/0x18
[<c013cfbc>] hrtimer_interrupt+0x124/0x1b8
[<c0115eba>] smp_apic_timer_interrupt+0x6c/0x7d
[<c0102a93>] default_idle+0x0/0x73
[<c0104b91>] apic_timer_interrupt+0x29/0x38
[<c0102a93>] default_idle+0x0/0x73
[<c0104b9b>] apic_timer_interrupt+0x33/0x38
[<c0102ae0>] default_idle+0x4d/0x73
[<c0102a93>] default_idle+0x0/0x73
[<c011bb2f>] native_safe_halt+0x2/0x3
[<c0102ae6>] default_idle+0x53/0x73
[<c01023d9>] cpu_idle+0xc5/0x121
[<c03adc71>] start_kernel+0x4ee/0x4f6
[<c03ad1b8>] unknown_bootoption+0x0/0x202
=======================
---------------------------
| preempt count: 00010003 ]
| 3-level deep critical section nesting:
----------------------------------------
.. [<c0102421>] .... cpu_idle+0x10d/0x121
.....[<00000000>] .. ( <= 0x0)
.. [<c02b65d7>] .... __spin_lock+0x10/0x3e
.....[<00000000>] .. ( <= 0x0)
.. [<c02b65d7>] .... __spin_lock+0x10/0x3e
.....[<00000000>] .. ( <= 0x0)
Going...
Going...
Results:
Results:
Draw Ax: 3376 10803
Draw Ax: 3376 10803
Going with test2.sh
Setting scheduler (200000 600000)
Setting scheduler (100000 600000)
SetSched done!
Threshold: 169468
SetSched done!
Sleeping...
Threshold: 169468
Sleeping...
Going...
Going...
Results:
Results:
Draw Ax: 6669 13788
Draw Ax: 6669 13788
Going with test3.sh
Setting scheduler (466000 700000)
Setting scheduler (200000 600000)
SetSched done!
SetSched done!
Threshold: 169468
Threshold: 169468
Sleeping...
Sleeping...
Going...
Going...
Results:
Results:
Draw Ax: 7779 16008
Draw Ax: 7779 16008
Going with test4.sh
Setting scheduler (390000 700000)
Setting scheduler (200000 600000)
SetSched done!
Threshold: 169468
SetSched done!
Sleeping...
Threshold: 169468
Sleeping...
Going...
Going...
Results:
Results:
