Re: 2.6.17-mm2 hrtimer code wedges at boot?

[Valdis.Kletnieks@vt.edu]

On Mon, 03 Jul 2006 03:13:39 +0200, Roman Zippel said:
> Hi,
> 
> On Fri, 30 Jun 2006, Valdis.Kletnieks@vt.edu 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@turing-police.cc.vt.edu) (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@redhat.com
[   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: pgpg1Zobn3VpC.pgp
Description: PGP signature