Re: 2.6.17-mm2 hrtimer code wedges at boot?

From: Valdis . Kletnieks
Date: Wed Jul 05 2006 - 00:29:09 EST


On Mon, 03 Jul 2006 03:13:39 +0200, Roman Zippel said:
> Hi,
>
> On Fri, 30 Jun 2006, Valdis.Kletnieks@xxxxxx wrote:
>
> > *AHA* I *found* the bugger, I think.
> >
> > In kernel/timer.c, we have:
> >
> > static void clocksource_adjust(struct clocksource *clock, s64 offset)
> > (s64 used for offset in multiple places).
> >
> > However, in other places, offset is a 'cycle_t', which is:
> >
> > include/linux/clocksource.h:typedef u64 cycle_t;
> >
> > So it looks like a signed/unsigned screwage.
>
> It's a possibility, but the signed/unsigned usage is pretty much
> intentional. The assumptation is that time only goes forward so nothing
> there should become negative, only adjustments happen in both directions.
> It's really weird why it's getting completely so out of control early
> during boot. It would be great if you could also test the patch below, it
> should trigger closer to when it goes wrong and help to analyze the
> problem (or at least rule out a number of possibilities).

Here you go.. For what it's worth, your debugging in clocksource_adjust seems
to only pop before we start userspace, and get_realtime_clock_ts only once
userspace starts.

My speculation about the RTC module turns out to be a red herring - I tried
a kernel with it built in, and the problem still manifested and cleared itself
early in rc.sysinit. Checking the code there, what seems to matter is that
rc.sysinit calls '/sbin/hwclock --hctosys --utc'.

Output of 'hwclock --debug':

hwclock from util-linux-2.13-pre6
Using /dev/rtc interface to clock.
Assuming hardware clock is kept in UTC time.
Waiting for clock tick...
...got clock tick
Time read from Hardware Clock: 2006/07/05 07:57:52
Hw clock time : 2006/07/05 07:57:52 = 1152086272 seconds since 1969
Calling settimeofday:
tv.tv_sec = 1152086272, tv.tv_usec = 0
tz.tz_minuteswest = 240

Absolutely nothing edifying there..

The dmesg, with all the suggested patches so far applied. Looks like something
starts off uninitialized - we get the first 'big adj' squawk right after we
allocate the console - we don't allocate the tsc timesource for another 4
seconds or so.

I'll bite - what *am* I using as a timesource for those first 4 seconds? :)

[ 0.000000] Linux version 2.6.17-mm2-test (valdis@xxxxxxxxxxxxxxxxxxxxxxx) (gcc version 4.1.1 20060629 (Red Hat 4.1.1-6)) #3 PREEMPT Tue Jul 4 18:42:05 EDT 2006
[ 0.000000] BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
[ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
[ 0.000000] BIOS-e820: 0000000000100000 - 000000002ffe2800 (usable)
[ 0.000000] BIOS-e820: 000000002ffe2800 - 0000000030000000 (reserved)
[ 0.000000] BIOS-e820: 00000000feda0000 - 00000000fee00000 (reserved)
[ 0.000000] BIOS-e820: 00000000ffb80000 - 0000000100000000 (reserved)
[ 0.000000] 767MB LOWMEM available.
[ 0.000000] On node 0 totalpages: 196578
[ 0.000000] DMA zone: 4096 pages, LIFO batch:0
[ 0.000000] Normal zone: 192482 pages, LIFO batch:31
[ 0.000000] DMI 2.3 present.
[ 0.000000] ACPI: RSDP (v000 DELL ) @ 0x000fde50
[ 0.000000] ACPI: RSDT (v001 DELL CPi R 0x27d40107 ASL 0x00000061) @ 0x000fde64
[ 0.000000] ACPI: FADT (v001 DELL CPi R 0x27d40107 ASL 0x00000061) @ 0x000fde90
[ 0.000000] ACPI: DSDT (v001 INT430 SYSFexxx 0x00001001 MSFT 0x0100000e) @ 0x00000000
[ 0.000000] ACPI: PM-Timer IO Port: 0x808
[ 0.000000] Allocating PCI resources starting at 40000000 (gap: 30000000:ceda0000)
[ 0.000000] Detected 1595.408 MHz processor.
[ 24.231372] Built 1 zonelists. Total pages: 196578
[ 24.231376] Kernel command line: console=tty0 vga=794 single
[ 24.231839] Local APIC disabled by BIOS -- you can enable it with "lapic"
[ 24.231854] mapped APIC to ffffd000 (01603000)
[ 24.231860] Enabling fast FPU save and restore... done.
[ 24.231864] Enabling unmasked SIMD FPU exception support... done.
[ 24.231871] Initializing CPU#0
[ 24.231977] CPU 0 irqstacks, hard=c04e2000 soft=c04e1000
[ 24.231982] PID hash table entries: 4096 (order: 12, 16384 bytes)
[ 24.232106] Console: colour dummy device 80x25
[ 24.232202] big adj at -299999 (4294314460971008,128,128,0)
[ 24.232214] clock jiffies: m:255960832,s:8,cl:4294667297,ci:1,xn:76031960832,xi:255960832,e:4294967296
[ 24.232983] big adj at -299998 (4294314460971008,64,64,0)
[ 24.232996] clock jiffies: m:255960960,s:8,cl:4294667298,ci:1,xn:76287921792,xi:255960960,e:4294967296
[ 24.233231] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 24.233991] big adj at -299997 (4294314460971008,64,64,0)
[ 24.234010] clock jiffies: m:255961024,s:8,cl:4294667299,ci:1,xn:76543882816,xi:255961024,e:4294967296
[ 24.234390] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 24.234978] big adj at -299996 (4294314460971008,32,32,0)
[ 24.234988] clock jiffies: m:255961088,s:8,cl:4294667300,ci:1,xn:76799843904,xi:255961088,e:3221225472
[ 24.235988] big adj at -299995 (4294314460971008,16,16,0)
[ 24.236009] clock jiffies: m:255961120,s:8,cl:4294667301,ci:1,xn:77055805024,xi:255961120,e:2147483648
[ 24.238986] big adj at -299992 (4294314460971008,-32,-32,0)
[ 24.239010] clock jiffies: m:255961141,s:8,cl:4294667304,ci:1,xn:77823688441,xi:255961141,e:-771751936
[ 24.239980] big adj at -299991 (4294314460971008,-16,-16,0)
[ 24.240001] clock jiffies: m:255961109,s:8,cl:4294667305,ci:1,xn:78079649550,xi:255961109,e:-587202560
[ 24.261902] Memory: 773428k/786312k available (2279k kernel code, 12284k reserved, 981k data, 192k init, 0k highmem)
[ 24.261916] Checking if this processor honours the WP bit even in supervisor mode... Ok.
[ 24.321842] Calibrating delay using timer specific routine.. 3192.23 BogoMIPS (lpj=1596118)
[ 24.321890] Security Framework v1.0.0 initialized
[ 24.321899] SELinux: Initializing.
[ 24.321916] SELinux: Starting in permissive mode
[ 24.321930] selinux_register_security: Registering secondary module capability
[ 24.321938] Capability LSM initialized as secondary
[ 24.321957] Mount-cache hash table entries: 512
[ 24.322102] CPU: After generic identify, caps: 3febf9ff 00000000 00000000 00000000 00000000 00000000 00000000
[ 24.322116] CPU: After vendor identify, caps: 3febf9ff 00000000 00000000 00000000 00000000 00000000 00000000
[ 24.322130] CPU: Trace cache: 12K uops, L1 D cache: 8K
[ 24.322137] CPU: L2 cache: 512K
[ 24.322142] CPU: After all inits, caps: 3febf9ff 00000000 00000000 00000080 00000000 00000000 00000000
[ 24.322152] Intel machine check architecture supported.
[ 24.322162] Intel machine check reporting enabled on CPU#0.
[ 24.322169] CPU0: Intel P4/Xeon Extended MCE MSRs (12) available
[ 24.322177] CPU0: Thermal monitoring enabled
[ 24.322196] CPU: Intel(R) Pentium(R) 4 Mobile CPU 1.60GHz stepping 04
[ 24.322210] Checking 'hlt' instruction... OK.
[ 24.325941] SMP alternatives: switching to UP code
[ 24.325948] Freeing SMP alternatives: 0k freed
[ 24.325953] ACPI: Core revision 20060608
[ 24.369235] ACPI: setting ELCR to 0200 (from 0800)
[ 24.374594] checking if image is initramfs... it is
[ 24.522694] Freeing initrd memory: 1031k freed
[ 24.523169] NET: Registered protocol family 16
[ 24.523769] ACPI: ACPI Dock Station Driver
[ 24.523784] ACPI: bus type pci registered
[ 24.537296] PCI: PCI BIOS revision 2.10 entry at 0xfbfee, last bus=2
[ 24.537303] Setting up standard PCI resources
[ 24.567815] ACPI: Interpreter enabled
[ 24.567828] ACPI: Using PIC for interrupt routing
[ 24.572140] ACPI: PCI Root Bridge [PCI0] (0000:00)
[ 24.572153] PCI: Probing PCI hardware (bus 00)
[ 24.572578] ACPI: Assume root bridge [\_SB_.PCI0] bus is 0
[ 24.648477] PCI quirk: region 0800-087f claimed by ICH4 ACPI/GPIO/TCO
[ 24.648490] PCI quirk: region 0880-08bf claimed by ICH4 GPIO
[ 24.648591] PCI: Ignoring BAR0-3 of IDE controller 0000:00:1f.1
[ 24.649169] Boot video device is 0000:01:00.0
[ 24.649943] PCI: Transparent bridge - 0000:00:1e.0
[ 24.650877] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[ 24.801769] ACPI: PCI Interrupt Link [LNKA] (IRQs 9 10 *11)
[ 24.803130] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 7) *11
[ 24.804452] ACPI: PCI Interrupt Link [LNKC] (IRQs 9 10 *11)
[ 24.805785] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 7 9 10 *11)
[ 24.809149] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.AGP_._PRT]
[ 24.810372] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PCIE._PRT]
[ 24.813313] ACPI: Power Resource [PADA] (on)
[ 24.814796] Linux Plug and Play Support v0.97 (c) Adam Belay
[ 24.814820] pnp: PnP ACPI init
[ 25.042773] pnp: PnP ACPI: found 17 devices
[ 25.042817] Intel 82802 RNG detected
[ 25.043398] usbcore: registered new driver usbfs
[ 25.043657] usbcore: registered new driver hub
[ 25.044250] PCI: Using ACPI for IRQ routing
[ 25.044259] PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report
[ 25.087170] pnp: 00:02: ioport range 0x4d0-0x4d1 has been reserved
[ 25.087181] pnp: 00:02: ioport range 0x800-0x805 could not be reserved
[ 25.087189] pnp: 00:02: ioport range 0x808-0x80f could not be reserved
[ 25.087202] pnp: 00:03: ioport range 0x806-0x807 has been reserved
[ 25.087209] pnp: 00:03: ioport range 0x810-0x85f could not be reserved
[ 25.087217] pnp: 00:03: ioport range 0x860-0x87f has been reserved
[ 25.087224] pnp: 00:03: ioport range 0x880-0x8bf has been reserved
[ 25.087231] pnp: 00:03: ioport range 0x8c0-0x8df has been reserved
[ 25.087237] pnp: 00:03: ioport range 0x8e0-0x8ff has been reserved
[ 25.087253] pnp: 00:04: ioport range 0xf000-0xf0fe has been reserved
[ 25.087261] pnp: 00:04: ioport range 0xf100-0xf1fe has been reserved
[ 25.087269] pnp: 00:04: ioport range 0xf200-0xf2fe has been reserved
[ 25.087276] pnp: 00:04: ioport range 0xf400-0xf4fe has been reserved
[ 25.087283] pnp: 00:04: ioport range 0xf500-0xf5fe has been reserved
[ 25.087291] pnp: 00:04: ioport range 0xf600-0xf6fe has been reserved
[ 25.087298] pnp: 00:04: ioport range 0xf800-0xf8fe has been reserved
[ 25.087306] pnp: 00:04: ioport range 0xf900-0xf9fe has been reserved
[ 25.087323] pnp: 00:09: ioport range 0x900-0x91f has been reserved
[ 25.087330] pnp: 00:09: ioport range 0x3f0-0x3f1 has been reserved
[ 25.087347] pnp: 00:0f: ioport range 0xbf40-0xbf5f has been reserved
[ 25.089593] PCI: Bridge: 0000:00:01.0
[ 25.089603] IO window: c000-cfff
[ 25.089614] MEM window: fc000000-fdffffff
[ 25.089624] PREFETCH window: d8000000-e7ffffff
[ 25.089680] PCI: Bus 3, cardbus bridge: 0000:02:01.0
[ 25.089687] IO window: 0000e000-0000e0ff
[ 25.089697] IO window: 0000e400-0000e4ff
[ 25.089708] PREFETCH window: 40000000-41ffffff
[ 25.089719] MEM window: f4000000-f5ffffff
[ 25.089729] PCI: Bus 7, cardbus bridge: 0000:02:01.1
[ 25.089735] IO window: 0000e800-0000e8ff
[ 25.089745] IO window: 00001000-000010ff
[ 25.089755] PREFETCH window: 42000000-43ffffff
[ 25.089765] MEM window: f6000000-f7ffffff
[ 25.089775] PCI: Bus 11, cardbus bridge: 0000:02:03.0
[ 25.089781] IO window: 00001400-000014ff
[ 25.089791] IO window: 00001800-000018ff
[ 25.089801] PREFETCH window: 44000000-45ffffff
[ 25.089812] MEM window: fa000000-fbffffff
[ 25.089821] PCI: Bridge: 0000:00:1e.0
[ 25.089829] IO window: e000-ffff
[ 25.089841] MEM window: f4000000-fbffffff
[ 25.089852] PREFETCH window: 40000000-46ffffff
[ 25.089888] PCI: Setting latency timer of device 0000:00:1e.0 to 64
[ 25.089916] PCI: Enabling device 0000:02:01.0 (0000 -> 0003)
[ 25.090851] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 25.090860] PCI: setting IRQ 11 as level-triggered
[ 25.090865] ACPI: PCI Interrupt 0000:02:01.0[A] -> Link [LNKD] -> GSI 11 (level, low) -> IRQ 11
[ 25.090903] PCI: Enabling device 0000:02:01.1 (0000 -> 0003)
[ 25.090912] ACPI: PCI Interrupt 0000:02:01.1[A] -> Link [LNKD] -> GSI 11 (level, low) -> IRQ 11
[ 25.090947] ACPI: PCI Interrupt 0000:02:03.0[A] -> Link [LNKD] -> GSI 11 (level, low) -> IRQ 11
[ 25.090997] NET: Registered protocol family 2
[ 25.100721] IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 25.101037] TCP established hash table entries: 131072 (order: 7, 524288 bytes)
[ 25.101582] TCP bind hash table entries: 65536 (order: 6, 262144 bytes)
[ 25.102109] TCP: Hash tables configured (established 131072 bind 65536)
[ 25.102118] TCP reno registered
[ 25.103491] Machine check exception polling timer started.
[ 25.103629] speedstep: frequency transition measured seems out of range (0 nSec), falling back to a safe one of 500000 nSec.
[ 25.115284] audit: initializing netlink socket (disabled)
[ 25.115311] audit(1152053784.178:1): initialized
[ 25.115507] VFS: Disk quotas dquot_6.5.1
[ 25.115537] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 25.115658] SELinux: Registering netfilter hooks
[ 25.121372] Initializing Cryptographic API
[ 25.121385] io scheduler noop registered
[ 25.121400] io scheduler anticipatory registered (default)
[ 25.121414] io scheduler deadline registered
[ 25.121434] io scheduler cfq registered
[ 25.122236] vesafb: framebuffer at 0xe0000000, mapped to 0xf0880000, using 5120k, total 32768k
[ 25.122249] vesafb: mode is 1280x1024x16, linelength=2560, pages=1
[ 25.122256] vesafb: protected mode interface info at c000:e140
[ 25.122262] vesafb: scrolling: redraw
[ 25.122269] vesafb: Truecolor: size=0:5:6:5, shift=0:11:5:0
[ 25.278897] Console: switching to colour frame buffer device 160x64
[ 25.279483] fb0: VESA VGA frame buffer device
[ 25.281108] ACPI: Video Device [VID] (multi-head: yes rom: no post: no)
[ 25.299034] Hangcheck: starting hangcheck timer 0.9.0 (tick is 180 seconds, margin is 60 seconds).
[ 25.299873] Hangcheck: Using get_cycles().
[ 25.300277] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
[ 25.301635] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 25.304229] 00:0d: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 25.306284] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 5
[ 25.306809] PCI: setting IRQ 5 as level-triggered
[ 25.306815] ACPI: PCI Interrupt 0000:00:1f.6[B] -> Link [LNKB] -> GSI 5 (level, low) -> IRQ 5
[ 25.307648] ACPI: PCI interrupt for device 0000:00:1f.6 disabled
[ 25.312431] RAMDISK driver initialized: 16 RAM disks of 10240K size 1024 blocksize
[ 25.315146] loop: loaded (max 8 devices)
[ 25.316718] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[ 25.317257] ACPI: PCI Interrupt 0000:02:00.0[A] -> Link [LNKC] -> GSI 11 (level, low) -> IRQ 11
[ 25.318098] 3c59x: Donald Becker and others. www.scyld.com/network/vortex.html
[ 25.318763] 0000:02:00.0: 3Com PCI 3c905C Tornado at f0804c00.
[ 25.342167] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
[ 25.342758] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
[ 25.343543] ICH3M: IDE controller at PCI slot 0000:00:1f.1
[ 25.344068] PCI: Enabling device 0000:00:1f.1 (0005 -> 0007)
[ 25.345514] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 11
[ 25.346049] ACPI: PCI Interrupt 0000:00:1f.1[A] -> Link [LNKA] -> GSI 11 (level, low) -> IRQ 11
[ 25.346888] ICH3M: chipset revision 2
[ 25.347232] ICH3M: not 100% native mode: will probe irqs later
[ 25.347780] ide0: BM-DMA at 0xbfa0-0xbfa7, BIOS settings: hda:DMA, hdb:DMA
[ 25.348499] ide1: BM-DMA at 0xbfa8-0xbfaf, BIOS settings: hdc:pio, hdd:pio
[ 25.349211] Probing IDE interface ide0...
[ 25.612743] hda: FUJITSU MHV2060AH, ATA DISK drive
[ 26.020116] hdb: TOSHIBA CD-RW/DVD-ROM SD-R2102, ATAPI CD/DVD-ROM drive
[ 26.075258] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
[ 26.076319] Probing IDE interface ide1...
[ 26.594608] hda: max request size: 128KiB
[ 26.622741] hda: 117210240 sectors (60011 MB) w/8192KiB Cache, CHS=65535/16/63, UDMA(100)
[ 26.628219] hda: cache flushes supported
[ 26.628628] hda: hda1 hda2
[ 26.638796] hdb: ATAPI 24X DVD-ROM CD-R/RW drive, 2048kB Cache, UDMA(33)
[ 26.666022] Uniform CD-ROM driver Revision: 3.20
[ 26.698666] ohci_hcd: 2006 May 24 USB 1.1 'Open' Host Controller (OHCI) Driver (PCI)
[ 26.698726] USB Universal Host Controller Interface driver v3.0
[ 26.726063] ACPI: PCI Interrupt 0000:00:1d.0[A] -> Link [LNKA] -> GSI 11 (level, low) -> IRQ 11
[ 26.753390] PCI: Setting latency timer of device 0000:00:1d.0 to 64
[ 26.753398] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[ 26.780846] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 1
[ 26.808385] uhci_hcd 0000:00:1d.0: irq 11, io base 0x0000bf80
[ 26.835528] usb usb1: new device found, idVendor=0000, idProduct=0000
[ 26.862572] usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1
[ 26.889563] usb usb1: Product: UHCI Host Controller
[ 26.916458] usb usb1: Manufacturer: Linux 2.6.17-mm2-test uhci_hcd
[ 26.943542] usb usb1: SerialNumber: 0000:00:1d.0
[ 26.971026] usb usb1: configuration #1 chosen from 1 choice
[ 26.998438] hub 1-0:1.0: USB hub found
[ 27.025153] hub 1-0:1.0: 2 ports detected
[ 27.152792] ACPI: PCI Interrupt 0000:00:1d.2[C] -> Link [LNKC] -> GSI 11 (level, low) -> IRQ 11
[ 27.180293] PCI: Setting latency timer of device 0000:00:1d.2 to 64
[ 27.180301] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[ 27.207849] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 2
[ 27.235744] uhci_hcd 0000:00:1d.2: irq 11, io base 0x0000bf20
[ 27.263385] usb usb2: new device found, idVendor=0000, idProduct=0000
[ 27.290913] usb usb2: new device strings: Mfr=3, Product=2, SerialNumber=1
[ 27.318344] usb usb2: Product: UHCI Host Controller
[ 27.345662] usb usb2: Manufacturer: Linux 2.6.17-mm2-test uhci_hcd
[ 27.373143] usb usb2: SerialNumber: 0000:00:1d.2
[ 27.401348] usb usb2: configuration #1 chosen from 1 choice
[ 27.429047] hub 2-0:1.0: USB hub found
[ 27.456193] hub 2-0:1.0: 2 ports detected
[ 27.789215] usb 2-1: new low speed USB device using uhci_hcd and address 2
[ 27.984255] usb 2-1: new device found, idVendor=045e, idProduct=0023
[ 28.010901] usb 2-1: new device strings: Mfr=1, Product=2, SerialNumber=0
[ 28.037435] usb 2-1: Product: Microsoft Trackball Optical®
[ 28.063757] usb 2-1: Manufacturer: Microsoft
[ 28.090448] usb 2-1: configuration #1 chosen from 1 choice
[ 28.134235] input: Microsoft Microsoft Trackball Optical® as /class/input/input0
[ 28.160854] input: USB HID v1.00 Mouse [Microsoft Microsoft Trackball Optical®] on usb-0000:00:1d.2-1
[ 28.187866] usbcore: registered new driver usbhid
[ 28.215125] drivers/usb/input/hid-core.c: v2.6:USB HID core driver
[ 28.242995] PNP: PS/2 Controller [PNP0303:KBC,PNP0f13:PS2M] at 0x60,0x64 irq 1,12
[ 28.274277] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 28.301472] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 28.328600] mice: PS/2 mouse device common for all mice
[ 28.355927] input: PC Speaker as /class/input/input1
[ 28.386381] input: AT Translated Set 2 keyboard as /class/input/input2
[ 28.412351] i2c /dev entries driver
[ 28.445100] device-mapper: 4.6.0-ioctl (2006-02-17) initialised: dm-devel@xxxxxxxxxx
[ 28.471229] EDAC MC: Ver: 2.0.0 Jul 4 2006
[ 28.497455] Advanced Linux Sound Architecture Driver Version 1.0.12rc1 (Thu Jun 22 13:55:50 2006 UTC).
[ 28.525942] ACPI: PCI Interrupt 0000:00:1f.5[B] -> Link [LNKB] -> GSI 5 (level, low) -> IRQ 5
[ 28.552844] PCI: Setting latency timer of device 0000:00:1f.5 to 64
[ 29.081381] input: DualPoint Stick as /class/input/input3
[ 29.126168] input: AlpsPS/2 ALPS DualPoint TouchPad as /class/input/input4
[ 29.163103] intel8x0_measure_ac97_clock: measured 50992 usecs
[ 29.190075] intel8x0: measured clock 94563 rejected
[ 29.216761] intel8x0: clocking to 48000
[ 29.246297] ALSA device list:
[ 29.272438] #0: Intel 82801CA-ICH3 with CS4205 at 0xd800, irq 5
[ 29.299153] TCP bic registered
[ 29.325327] Initializing IPsec netlink socket
[ 29.351386] NET: Registered protocol family 1
[ 29.377536] NET: Registered protocol family 10
[ 29.403357] lo: Disabled Privacy Extensions
[ 29.428765] IPv6 over IPv4 tunneling driver
[ 29.454410] NET: Registered protocol family 17
[ 29.479450] NET: Registered protocol family 15
[ 29.504193] Using IPI Shortcut mode
[ 29.528533] Time: tsc clocksource has been installed.
[ 29.552855] clock changed at -296333 (4294314460971008)
[ 29.577109] clock tsc: m:2628985,s:22,cl:47171945132,ci:1595166,xn:0,xi:4193667486510,e:0
[ 29.601869] big adj at -296332 (4294314460971008,-16,-25522656,-11031712)
[ 29.626688] clock tsc: m:2628985,s:22,cl:47288392250,ci:1595166,xn:148610636380190,xi:4193667486510,e:-76300711936
[ 29.652263] big adj at -296331 (4294314460971008,512,816724992,737704960)
[ 29.677968] clock tsc: m:2628969,s:22,cl:47368150550,ci:1595166,xn:358292745604602,xi:4193641963854,e:1193037240320
[ 29.704510] big adj at -296330 (4294314460971008,-8192,-13067599872,-2961899520)
[ 29.731241] clock tsc: m:2629481,s:22,cl:47452694348,ci:1595166,xn:580598318408480,xi:4194458688846,e:-41883408859136
[ 29.758931] big adj at -296329 (4294314460971008,262144,418163195904,304081797120)
[ 29.786568] clock tsc: m:2621289,s:22,cl:47538833312,ci:1595166,xn:806396399112596,xi:4181391088974,e:647244064829440
[ 29.814707] big adj at -296328 (4294314460971008,-8388608,-13381222268928,-7813787025408)
[ 29.843116] clock tsc: m:2883433,s:22,cl:47628162608,ci:1595166,xn:1063667357268644,xi:4599554284878,e:-22744806385192960
[ 29.872317] big adj at -296327 (4294314460971008,1,1595166,446268)
[ 29.901485] clock tsc: m:4289462121,s:22,cl:47720682236,ci:1595166,xn:562144401219152,xi:18446735292041567566,e:753587310949187584
[ 29.931755] big adj at -296326 (4294314460971008,1,1595166,1284562)
[ 29.962006] clock tsc: m:4289462122,s:22,cl:47814797030,ci:1595166,xn:44026083828728,xi:18446735292043162732,e:1537505019520821248
[ 29.993322] big adj at -296325 (4294314460971008,1,1595166,734154)
[ 30.024732] clock tsc: m:4289462123,s:22,cl:47913697322,ci:1595166,xn:18207168308574885266,xi:18446735292044757898,e:2361282850206533632
[ 30.057404] big adj at -296324 (4294314460971008,1,1595166,1013902)
[ 30.090153] clock tsc: m:4289462124,s:22,cl:48015787946,ci:1595166,xn:17938170826129443784,xi:18446735292046353064,e:3211634054207305728
[ 30.124811] Freeing unused kernel memory: 192k freed
[ 30.158910] Write protecting the kernel read-only data: 402k
[ 30.502924] unexpected nsec: -249310867,2962848525
[ 30.534582] clock tsc: m:4289462438,s:22,cl:48778277294,ci:1595166,xn:15924728282382833372,xi:18446735292547235188,e:-8884147731732662272
[ 30.567853] unexpected nsec: -1962978502,1374054342
[ 30.601090] clock tsc: m:4289462436,s:22,cl:48885153416,ci:1595166,xn:15654512304741409624,xi:18446735292544044856,e:-7993970621383804928
[ 78.648061] kjournald starting. Commit interval 5 seconds
[ 78.681141] EXT3-fs: mounted filesystem with ordered data mode.
[ 79.511997] security: 6 users, 5 roles, 1965 types, 81 bools, 1 sens, 256 cats
[ 79.544616] security: 58 classes, 123884 rules
[ 79.579276] SELinux: Completing initialization.
[ 79.611956] SELinux: Setting up existing superblocks.
[ 79.677464] SELinux: initialized (dev dm-0, type ext3), uses xattr
[ 79.829815] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
[ 79.863240] SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts
[ 79.896423] SELinux: initialized (dev debugfs, type debugfs), uses genfs_contexts
[ 79.929696] SELinux: initialized (dev selinuxfs, type selinuxfs), uses genfs_contexts
[ 79.963020] SELinux: initialized (dev mqueue, type mqueue), uses transition SIDs
[ 79.996350] SELinux: initialized (dev devpts, type devpts), uses transition SIDs
[ 80.028943] SELinux: initialized (dev eventpollfs, type eventpollfs), uses genfs_contexts
[ 80.061259] SELinux: initialized (dev inotifyfs, type inotifyfs), uses genfs_contexts
[ 80.093142] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
[ 80.124561] SELinux: initialized (dev futexfs, type futexfs), uses genfs_contexts
[ 80.155563] SELinux: initialized (dev pipefs, type pipefs), uses task SIDs
[ 80.186435] SELinux: initialized (dev sockfs, type sockfs), uses task SIDs
[ 80.216576] SELinux: initialized (dev proc, type proc), uses genfs_contexts
[ 80.245849] SELinux: initialized (dev bdev, type bdev), uses genfs_contexts
[ 80.274340] SELinux: initialized (dev rootfs, type rootfs), uses genfs_contexts
[ 80.302334] SELinux: initialized (dev sysfs, type sysfs), uses genfs_contexts
[ 80.332660] audit(1152066829.655:2): policy loaded auid=4294967295
[ 80.360059] audit(1152066829.642:3): avc: granted { load_policy } for pid=1 comm="init" scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security
[ 81.871761] unexpected nsec: -1188339803,701954360
[ 81.897554] clock tsc: m:1965639796,s:22,cl:130830426002,ci:1595166,xn:17365880163142832508,xi:18446741971357700448,e:-6392280673125578752
[ 129.407146] Real Time Clock Driver v1.12ac


Attachment: pgp00000.pgp
Description: PGP signature