Date: Sun, 28 May 2000 03:33:57 -0700 (PDT) From: eo@ertw.ca To: freebsd-gnats-submit@FreeBSD.org Subject: kern/18858: microuptime() errors even after disabling APM on VIA KX133 chipset Message-ID: <20000528103357.00C3837B51C@hub.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 18858
>Category: kern
>Synopsis: microuptime() errors even after disabling APM on VIA KX133 chipset
>Confidential: no
>Severity: serious
>Priority: high
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Sun May 28 03:40:00 PDT 2000
>Closed-Date:
>Last-Modified:
>Originator: Bart Kus
>Release: 4.0-RELEASE
>Organization:
ERTW Canada
>Environment:
FreeBSD betsy.bart.net 4.0-RELEASE FreeBSD 4.0-RELEASE #0: Mon Mar 20 22:50:22 GMT 2000 root@monster.cdrom.com:/usr/src/sys/compile/GENERIC i386
>Description:
Endless
microuptime() went backwards (2288.362908 -> 2288,344887)
microuptime() went backwards (2288.362908 -> 2288,348850)
microuptime() went backwards (2288.393310 -> 2288,371213)
messages, sprinkled with:
calcru: negative time of 1419 usec for pid 87333 (cat)
or whatever happens to be running at the time.
This causes syslogd to go insane with HD IO (making the problem worse), and causes ps to report broken run times.
Disabling the APM features of the BIOS does no good. And this isn't an SMP PIIIX chipset.
Here's the output of /var/run/dmesg.boot:
Copyright (c) 1992-2000 The FreeBSD Project.
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California. All rights reserved.
FreeBSD 4.0-RELEASE #0: Mon Mar 20 22:50:22 GMT 2000
root@monster.cdrom.com:/usr/src/sys/compile/GENERIC
Timecounter "i8254" frequency 1193182 Hz
CPU: AMD Athlon(tm) Processor (700.03-MHz 686-class CPU)
Origin = "AuthenticAMD" Id = 0x621 Stepping = 1
Features=0x183f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
AMD Features=0xc0400000<AMIE,DSP,3DNow!>
real memory = 805240832 (786368K bytes)
config> di pcic0
config> di ppc0
config> di sn0
config> di lnc0
config> di le0
config> di ie0
config> di fe0
config> di ed0
config> di cs0
config> di bt0
config> di aic0
config> di aha0
config> di adv0
config> q
avail memory = 777252864 (759036K bytes)
Preloaded elf kernel "kernel" at 0xc03c0000.
Preloaded userconfig_script "/boot/kernel.conf" at 0xc03c009c.
Pentium Pro MTRR support enabled
md0: Malloc disk
npx0: <math processor> on motherboard
npx0: INT 16 interface
pcib0: <Host to PCI bridge> on motherboard
pci0: <PCI bus> on pcib0
pcib2: <PCI to PCI bridge (vendor=1106 device=8391)> at device 1.0 on pci0
pci1: <PCI bus> on pcib2
isab0: <VIA 82C686 PCI-ISA bridge> at device 7.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 82C686 ATA66 controller> port 0xe000-0xe00f at device 7.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
fxp0: <Intel EtherExpress Pro 10/100B Ethernet> port 0xec00-0xec3f mem 0xd5400000-0xd54fffff,0xd5500000-0xd5500fff irq 11 at device 15.0 on pci0
fxp0: Ethernet address 00:d0:b7:73:47:7b
fxp0: supplying EUI64: 00:d0:b7:ff:fe:73:47:7b
pci0: <S3 ViRGE graphics accelerator> at 17.0 irq 10
pcib1: <Host to PCI bridge> on motherboard
pci2: <PCI bus> on pcib1
fdc0: <NEC 72065B or clone> at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0
fdc0: FIFO enabled, 8 bytes threshold
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
atkbdc0: <keyboard controller (i8042)> at port 0x60-0x6f on isa0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
sc0: <System console> on isa0
sc0: VGA <16 virtual consoles, flags=0x200>
sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
sio0: type 16550A
sio1 at port 0x2f8-0x2ff irq 3 on isa0
sio1: type 16550A
ad0: 39082MB <Maxtor 54098U8> [79406/16/63] at ata0-master using UDMA66
Mounting root from ufs:/dev/ad0s1a
I'm not sure what to include from sysctl, so here's the whole thing:
kern.ostype: FreeBSD
kern.osrelease: 4.0-RELEASE
kern.osrevision: 199506
kern.version: FreeBSD 4.0-RELEASE #0: Mon Mar 20 22:50:22 GMT 2000
root@monster.cdrom.com:/usr/src/sys/compile/GENERIC
kern.maxvnodes: 48767
kern.maxproc: 532
kern.maxfiles: 1064
kern.argmax: 65536
kern.securelevel: -1
kern.hostname: betsy.bart.net
kern.hostid: 0
kern.clockrate: { hz = 100, tick = 10000, tickadj = 5, profhz = 1024, stathz = 128 }
kern.posix1version: 199309
kern.ngroups: 16
kern.job_control: 1
kern.saved_ids: 0
kern.boottime: { sec = 959505295, usec = 973862 } Sun May 28 04:14:55 2000
kern.domainname:
kern.osreldate: 400017
kern.bootfile: /kernel
kern.maxfilesperproc: 1064
kern.maxprocperuid: 531
kern.dumpdev: { major = 255, minor = -65281 }
kern.ipc.maxsockbuf: 262144
kern.ipc.sockbuf_waste_factor: 8
kern.ipc.somaxconn: 128
kern.ipc.max_linkhdr: 16
kern.ipc.max_protohdr: 60
kern.ipc.max_hdr: 76
kern.ipc.max_datalen: 20
kern.ipc.nmbclusters: 1024
kern.ipc.mbuf_wait: 32
kern.ipc.nmbufs: 4096
kern.ipc.maxsockets: 1064
kern.dummy: 0
kern.ps_strings: -1077936144
kern.usrstack: -1077936128
kern.logsigexit: 1
kern.cam.cd.changer.min_busy_seconds: 5
kern.cam.cd.changer.max_busy_seconds: 15
kern.fallback_elf_brand: none
kern.init_path: /sbin/init:/sbin/oinit:/sbin/init.bak:/stand/sysinstall
kern.module_path: /;/boot/;/modules/
kern.acct_suspend: 2
kern.acct_resume: 4
kern.acct_chkfreq: 15
kern.timecounter.method: 0
kern.timecounter.hardware: i8254
kern.ps_arg_cache_limit: 256
kern.ps_argsopen: 1
kern.fast_vfork: 1
kern.randompid: 0
kern.shutdown.poweroff_delay: 5000
kern.shutdown.kproc_shutdown_wait: 60
kern.sugid_coredump: 0
kern.corefile: %N.core
kern.quantum: 100000
kern.ccpu: 1948
kern.fscale: 2048
kern.devstat.numdevs: 3
kern.devstat.generation: 3
kern.devstat.version: 4
kern.nselcoll: 0
kern.consmute: 0
kern.filedelay: 30
kern.dirdelay: 29
kern.metadelay: 28
kern.chroot_allow_open_directories: 1
vm.loadavg: { 0.30 0.17 0.12 }
vm.v_free_min: 1296
vm.v_free_target: 4221
vm.v_free_reserved: 333
vm.v_inactive_target: 6331
vm.v_cache_min: 4221
vm.v_cache_max: 8442
vm.v_pageout_free_min: 34
vm.pageout_algorithm: 0
vm.swap_enabled: 1
vm.swap_async_max: 4
vm.swap_idle_threshold1: 2
vm.swap_idle_threshold2: 10
vm.v_free_severe: 814
vm.stats.sys.v_swtch: 1247260
vm.stats.sys.v_trap: 2730575
vm.stats.sys.v_syscall: 9085489
vm.stats.sys.v_intr: 1257786
vm.stats.sys.v_soft: 506181
vm.stats.vm.v_vm_faults: 2582854
vm.stats.vm.v_cow_faults: 798388
vm.stats.vm.v_cow_optim: 0
vm.stats.vm.v_zfod: 873626
vm.stats.vm.v_ozfod: 788300
vm.stats.vm.v_swapin: 0
vm.stats.vm.v_swapout: 0
vm.stats.vm.v_swappgsin: 0
vm.stats.vm.v_swappgsout: 0
vm.stats.vm.v_vnodein: 629
vm.stats.vm.v_vnodeout: 0
vm.stats.vm.v_vnodepgsin: 4395
vm.stats.vm.v_vnodepgsout: 0
vm.stats.vm.v_intrans: 10
vm.stats.vm.v_reactivated: 292
vm.stats.vm.v_pdwakeups: 19
vm.stats.vm.v_pdpages: 75497
vm.stats.vm.v_dfree: 0
vm.stats.vm.v_pfree: 1265765
vm.stats.vm.v_tfree: 2599053
vm.stats.vm.v_page_size: 4096
vm.stats.vm.v_page_count: 192942
vm.stats.vm.v_free_reserved: 333
vm.stats.vm.v_free_target: 4221
vm.stats.vm.v_free_min: 1296
vm.stats.vm.v_free_count: 449
vm.stats.vm.v_wire_count: 28414
vm.stats.vm.v_active_count: 7471
vm.stats.vm.v_inactive_target: 6331
vm.stats.vm.v_inactive_count: 149993
vm.stats.vm.v_cache_count: 6615
vm.stats.vm.v_cache_min: 4221
vm.stats.vm.v_cache_max: 8442
vm.stats.vm.v_pageout_free_min: 34
vm.stats.vm.v_interrupt_free_min: 2
vm.stats.misc.zero_page_count: 348
vm.stats.misc.cnt_prezero: 797026
vm.max_proc_mmap: 43690
vm.pageout_stats_max: 4221
vm.pageout_full_stats_interval: 20
vm.pageout_stats_interval: 5
vm.pageout_stats_free_max: 5
vm.swap_idle_enabled: 0
vm.defer_swapspace_pageouts: 0
vm.disable_swapspace_pageouts: 0
vm.max_page_launder: 32
vm.zone:
ITEM SIZE LIMIT USED FREE REQUESTS
PIPE: 160, 0, 28, 74, 275
SWAPMETA: 160, 385884, 0, 0, 0
unpcb: 64, 0, 85, 107, 164
ripcb: 192, 1064, 0, 21, 0
tcpcb: 544, 1064, 23, 12, 202
udpcb: 192, 1064, 6, 36, 206
tcpcb: 544, 1064, 0, 0, 0
socket: 192, 1064, 114, 33, 577
AIOLIO: 704, 0, 0, 0, 0
AIOL: 64, 0, 0, 0, 0
AIOCB: 128, 0, 0, 0, 0
AIOP: 32, 0, 0, 0, 0
AIO: 96, 0, 0, 0, 0
NFSNODE: 320, 0, 0, 0, 0
NFSMOUNT: 544, 0, 0, 0, 0
VNODE: 160, 0, 81493, 43, 80856
NAMEI: 1024, 0, 0, 24, 624440
VMSPACE: 192, 0, 51, 525, 87637
PROC: 416, 0, 55, 533, 87638
DP fakepg: 64, 0, 6, 122, 5
PV ENTRY: 28, 499566, 31827, 164756, 18896820
MAP ENTRY: 48, 0, 6665, 4768, 2077827
KMAP ENTRY: 48, 48363, 1264, 139, 10757
MAP: 108, 0, 7, 3, 7
VM OBJECT: 96, 0, 67638, 1540, 1217129
vm.zone_kmem_pages: 30
vm.zone_kmem_kvaspace: 74326016
vm.zone_kern_pages: 5061
vfs.nfs.nfs_privport: 0
vfs.nfs.async: 0
vfs.nfs.commit_blks: 0
vfs.nfs.commit_miss: 0
vfs.nfs.realign_test: 0
vfs.nfs.realign_count: 0
vfs.nfs.gatherdelay: 10000
vfs.nfs.gatherdelay_v3: 0
vfs.nfs.defect: 0
vfs.nfs.diskless_valid: 0
vfs.nfs.diskless_rootpath:
vfs.nfs.diskless_swappath:
vfs.nfs.access_cache_timeout: 60
vfs.nfs.nfsv3_commit_on_close: 0
vfs.numdirtybuffers: 7
vfs.hidirtybuffers: 2786
vfs.numfreebuffers: 11060
vfs.lofreebuffers: 619
vfs.hifreebuffers: 1238
vfs.runningbufspace: 0
vfs.maxbufspace: 45363200
vfs.hibufspace: 44707840
vfs.bufspace: 44426240
vfs.maxbdrun: 64
vfs.vmiospace: 43116544
vfs.maxmallocbufspace: 2235392
vfs.bufmallocspace: 1211392
vfs.kvafreespace: 65536
vfs.getnewbufcalls: 172844
vfs.getnewbufrestarts: 133286
vfs.vmiodirenable: 0
vfs.cache.numneg: 247
vfs.cache.numcache: 81744
vfs.cache.numcalls: 1657326
vfs.cache.dothits: 82878
vfs.cache.dotdothits: 17104
vfs.cache.numchecks: 3352064
vfs.cache.nummiss: 133178
vfs.cache.nummisszap: 48
vfs.cache.numposzaps: 325
vfs.cache.numposhits: 1169762
vfs.cache.numnegzaps: 144
vfs.cache.numneghits: 253887
vfs.cache.numcwdcalls: 208
vfs.cache.numcwdfail1: 0
vfs.cache.numcwdfail2: 0
vfs.cache.numcwdfail3: 0
vfs.cache.numcwdfail4: 0
vfs.cache.numcwdfound: 208
vfs.write_behind: 1
vfs.reassignbufcalls: 39666
vfs.reassignbufloops: 0
vfs.reassignbufsortgood: 4361
vfs.reassignbufsortbad: 15317
vfs.reassignbufmethod: 1
vfs.timestamp_precision: 0
vfs.usermount: 0
vfs.aio.max_aio_per_proc: 32
vfs.aio.max_aio_queue_per_proc: 256
vfs.aio.max_aio_procs: 32
vfs.aio.num_aio_procs: 0
vfs.aio.num_queue_count: 0
vfs.aio.max_aio_queue: 1024
vfs.aio.target_aio_procs: 4
vfs.aio.max_buf_aio: 16
vfs.aio.num_buf_aio: 0
vfs.aio.aiod_lifetime: 3000
vfs.aio.aiod_timeout: 1000
vfs.ffs.doreallocblks: 1
vfs.ffs.doasyncfree: 1
net.local.stream.sendspace: 8192
net.local.stream.recvspace: 8192
net.local.dgram.maxdgram: 2048
net.local.dgram.recvspace: 4096
net.local.inflight: 0
net.inet.ip.portrange.lowfirst: 1023
net.inet.ip.portrange.lowlast: 600
net.inet.ip.portrange.first: 1024
net.inet.ip.portrange.last: 5000
net.inet.ip.portrange.hifirst: 49152
net.inet.ip.portrange.hilast: 65535
net.inet.ip.forwarding: 0
net.inet.ip.redirect: 1
net.inet.ip.ttl: 64
net.inet.ip.rtexpire: 3600
net.inet.ip.rtminexpire: 10
net.inet.ip.rtmaxcache: 128
net.inet.ip.sourceroute: 0
net.inet.ip.intr_queue_maxlen: 50
net.inet.ip.intr_queue_drops: 0
net.inet.ip.accept_sourceroute: 0
net.inet.ip.fastforwarding: 0
net.inet.ip.keepfaith: 0
net.inet.ip.gifttl: 30
net.inet.ip.subnets_are_local: 0
net.inet.icmp.maskrepl: 0
net.inet.icmp.icmplim: 200
net.inet.icmp.drop_redirect: 0
net.inet.icmp.log_redirect: 0
net.inet.icmp.bmcastecho: 0
net.inet.tcp.rfc1323: 1
net.inet.tcp.rfc1644: 0
net.inet.tcp.mssdflt: 512
net.inet.tcp.keepidle: 7200000
net.inet.tcp.keepintvl: 75000
net.inet.tcp.sendspace: 16384
net.inet.tcp.recvspace: 16384
net.inet.tcp.keepinit: 75000
net.inet.tcp.delacktime: 100
net.inet.tcp.v6mssdflt: 1024
net.inet.tcp.log_in_vain: 0
net.inet.tcp.blackhole: 0
net.inet.tcp.delayed_ack: 1
net.inet.tcp.path_mtu_discovery: 1
net.inet.tcp.slowstart_flightsize: 1
net.inet.tcp.local_slowstart_flightsize: 65535
net.inet.tcp.tcbhashsize: 512
net.inet.tcp.pcbcount: 23
net.inet.tcp.msl: 30000
net.inet.tcp.always_keepalive: 1
net.inet.udp.checksum: 1
net.inet.udp.maxdgram: 9216
net.inet.udp.recvspace: 42080
net.inet.udp.log_in_vain: 0
net.inet.udp.blackhole: 0
net.inet.raw.maxdgram: 8192
net.inet.raw.recvspace: 8192
net.link.generic.system.ifcount: 10
net.link.ether.inet.prune_intvl: 300
net.link.ether.inet.max_age: 1200
net.link.ether.inet.host_down_time: 20
net.link.ether.inet.maxtries: 5
net.link.ether.inet.useloopback: 1
net.link.ether.inet.proxyall: 0
net.inet6.ip6.forwarding: 0
net.inet6.ip6.redirect: 1
net.inet6.ip6.hlim: 64
net.inet6.ip6.maxfragpackets: 200
net.inet6.ip6.accept_rtadv: 0
net.inet6.ip6.keepfaith: 0
net.inet6.ip6.log_interval: 5
net.inet6.ip6.hdrnestlimit: 50
net.inet6.ip6.dad_count: 1
net.inet6.ip6.auto_flowlabel: 1
net.inet6.ip6.defmcasthlim: 1
net.inet6.ip6.gifhlim: 30
net.inet6.ip6.kame_version: 19991101/FreeBSD4.x
net.inet6.ip6.use_deprecated: 1
net.inet6.ip6.rr_prune: 5
net.inet6.ip6.mapped_addr: 1
net.inet6.icmp6.rediraccept: 1
net.inet6.icmp6.redirtimeout: 600
net.inet6.icmp6.errratelimit: 1000
net.inet6.icmp6.nd6_prune: 1
net.inet6.icmp6.nd6_delay: 5
net.inet6.icmp6.nd6_umaxtries: 3
net.inet6.icmp6.nd6_mmaxtries: 3
net.inet6.icmp6.nd6_useloopback: 1
net.inet6.icmp6.nd6_proxyall: 0
debug.mddebug: 0
debug.elf_trace: 0
debug.boothowto: -2147483648
debug.free_devt: 0
debug.fdexpand: 7
debug.sizeof.vnode: 160
debug.sizeof.proc: 404
debug.sizeof.specinfo: 76
debug.sizeof.disklabel: 276
debug.sizeof.diskslices: 1820
debug.sizeof.disk: 296
debug.ttydebug: 0
debug.nchash: 65535
debug.ncnegfactor: 16
debug.numneg: 247
debug.numcache: 81744
debug.vfscache: 1
debug.vnsize: 160
debug.ncsize: 36
debug.disablecwd: 0
debug.numvnodes: 81493
debug.wantfreevnodes: 25
debug.freevnodes: 967
debug.rush_requests: 0
debug.bpf_bufsize: 4096
debug.bpf_maxbufsize: 524288
debug.if_tun_debug: 0
debug.do_tcpdrain: 1
debug.ncr_debug: 0
debug.dircheck: 0
hw.machine: i386
hw.model: AMD Athlon(tm) Processor
hw.ncpu: 1
hw.byteorder: 1234
hw.physmem: 801857536
hw.usermem: 685477888
hw.pagesize: 4096
hw.floatingpoint: 1
hw.machine_arch: i386
hw.atamodes: dma,---,
hw.availpages: 195599
machdep.consdev: { major = 12, minor = 255 }
machdep.adjkerntz: 18000
machdep.disable_rtc_set: 0
machdep.wall_cmos_clock: 1
machdep.an_cache_mcastonly: 0
machdep.an_cache_iponly: 1
machdep.do_dump: 1
machdep.pccard.pcic_resume_reset: 1
machdep.enable_panic_key: 0
machdep.apm_suspend_delay: 1
machdep.apm_standby_delay: 1
machdep.ispc98: 0
machdep.msgbuf: e() went backwards (2281.382591 -> 2281,340457)
microuptime() went backwards (2281.400624 -> 2281,390329)
microuptime() went backwards (2281.413578 -> 2281,396546)
microuptime() went backwards (2281.443450 -> 2281,417667)
microuptime() went backwards (2281.454404 -> 2281,414287)
microuptime() went backwards (2281.454404 -> 2281,452263)
microuptime() went backwards (2281.454404 -> 2281,436947)
microuptime() went backwards (2281.454404 -> 2281,450893)
microuptime() went backwards (2281.479345 -> 2281,434933)
microuptime() went backwards (2281.479345 -> 2281,464541)
microuptime() went backwards (2281.491276 -> 2281,453302)
microuptime() went backwards (2281.491276 -> 2281,474757)
microuptime() went backwards (2281.491276 -> 2281,465448)
microuptime() went backwards (2281.491276 -> 2281,484972)
microuptime() went backwards (2281.491276 -> 2281,486690)
microuptime() went backwards (2281.491113 -> 2281,480517)
microuptime() went backwards (2281.501758 -> 2281,481722)
microuptime() went backwards (2281.501758 -> 2281,489664)
microuptime() went backwards (2281.495673 -> 2281,489367)
microuptime() went backwards (2281.547000 -> 2281,500231)
microuptime() went backwards (2281.516539 -> 2281,514311)
calcru: negative time of 0 usec for pid 87174 (cat)
microuptime() went backwards (2281.564218 -> 2281,557571)
microuptime() went backwards (2281.583368 -> 2281,554750)
microuptime() went backwards (2281.583368 -> 2281,579173)
microuptime() went backwards (2281.585527 -> 2281,576004)
calcru: negative time of 22755 usec for pid 87176 (cat)
microuptime() went backwards (2281.608831 -> 2281,605318)
microuptime() went backwards (2281.622484 -> 2281,605237)
microuptime() went backwards (2281.647635 -> 2281,628543)
microuptime() went backwards (2281.660000 -> 2281,631680)
microuptime() went backwards (2281.660000 -> 2281,649273)
microuptime() went backwards (2281.668285 -> 2281,625805)
microuptime() went backwards (2281.668285 -> 2281,627310)
microuptime() went backwards (2281.681288 -> 2281,659619)
microuptime() went backwards (2281.738075 -> 2281,714690)
microuptime() went backwards (2281.748505 -> 2281,725550)
microuptime() went backwards (2281.739755 -> 2281,-694643184)
microuptime() went backwards (2281.816805 -> 2281,787412)
microuptime() went backwards (2281.830713 -> 2281,-694566817)
microuptime() went backwards (2281.898062 -> 2281,869956)
microuptime() went backwards (2281.911496 -> 2281,861720)
microuptime() went backwards (2281.911496 -> 2281,881030)
microuptime() went backwards (2281.911496 -> 2281,900340)
microuptime() went backwards (2281.911496 -> 2281,885024)
microuptime() went backwards (2281.911496 -> 2281,901973)
microuptime() went backwards (2281.911496 -> 2281,881937)
microuptime() went backwards (2281.911496 -> 2281,903392)
microuptime() went backwards (2281.911496 -> 2281,893654)
microuptime() went backwards (2281.952145 -> 2281,940560)
microuptime() went backwards (2282.043801 -> 2282,030845)
microuptime() went backwards (2282.066701 -> 2282,066189)
microuptime() went backwards (2282.090127 -> 2282,080389)
microuptime() went backwards (2282.147450 -> 2282,122348)
microuptime() went backwards (2282.185290 -> 2282,158901)
microuptime() went backwards (2282.181229 -> 2282,166556)
microuptime() went backwards (2282.208295 -> 2282,183622)
microuptime() went backwards (2282.248711 -> 2282,212881)
microuptime() went backwards (2282.248711 -> 2282,228329)
microuptime() went backwards (2282.256781 -> 2282,212584)
microuptime() went backwards (2282.256781 -> 2282,242836)
microuptime() went backwards (2282.269571 -> 2282,231596)
microuptime() went backwards (2282.269571 -> 2282,252837)
microuptime() went backwards (2282.269571 -> 2282,242026)
microuptime() went backwards (2282.269571 -> 2282,259405)
microuptime() went backwards (2282.265116 -> 2282,262243)
microuptime() went backwards (2282.267622 -> 2282,263463)
microuptime() went backwards (2282.299925 -> 2282,287613)
microuptime() went backwards (2282.403563 -> 2282,-694994396)
microuptime() went backwards (2282.430781 -> 2282,427265)
microuptime() went backwards (2282.435573 -> 2282,425192)
microuptime() went backwards (2282.450637 -> 2282,-694936380)
microuptime() went backwards (2282.483073 -> 2282,475696)
microuptime() went backwards (2282.483073 -> 2282,476046)
microuptime() went backwards (2282.504252 -> 2282,-694883192)
microuptime() went backwards (2282.549143 -> 2282,520395)
microuptime() went backwards (2282.549143 -> 2282,539705)
microuptime() went backwards (2282.549143 -> 2282,510874)
microuptime() went backwards (2282.549143 -> 2282,548635)
microuptime() went backwards (2282.549143 -> 2282,536752)
microuptime() went backwards (2282.561211 -> 2282,529588)
microuptime() went backwards (2282.561211 -> 2282,560055)
microuptime() went backwards (2282.588507 -> 2282,550103)
microuptime() went backwards (2282.588507 -> 2282,573704)
microuptime() went backwards (2282.588507 -> 2282,583705)
microuptime() went backwards (2282.588507 -> 2282,560020)
microuptime() went backwards (2282.588507 -> 2282,578472)
microuptime() went backwards (2282.600357 -> 2282,586757)
microuptime() went backwards (2282.630872 -> 2282,586460)
microuptime() went backwards (2282.630872 -> 2282,609121)
microuptime() went backwards (2282.656799 -> 2282,643712)
microuptime() went backwards (2282.656799 -> 2282,648564)
microuptime() went backwards (2282.670795 -> 2282,643892)
microuptime() went backwards (2282.670795 -> 2282,665133)
microuptime() went backwards (2282.670795 -> 2282,668141)
microuptime() went backwards (2282.678011 -> 2282,658619)
microuptime() went backwards (2282.683722 -> 2282,682997)
microuptime() went backwards (2282.728960 -> 2282,688840)
microuptime() went backwards (2282.728960 -> 2282,710510)
microuptime() went backwards (2282.719736 -> 2282,709141)
microuptime() went backwards (2282.719736 -> 2282,717818)
microuptime() went backwards (2282.734769 -> 2282,733828)
microuptime() went backwards (2282.758142 -> 2282,742826)
microuptime() went backwards (2282.798108 -> 2282,777512)
microuptime() went backwards (2282.815713 -> 2282,811209)
microuptime() went backwards (2282.843658 -> 2282,795600)
microuptime() went backwards (2282.843658 -> 2282,815553)
microuptime() went backwards (2282.824993 -> 2282,805172)
microuptime() went backwards (2282.824993 -> 2282,811958)
microuptime() went backwards (2282.836633 -> 2282,834833)
microuptime() went backwards (2282.934029 -> 2282,928367)
microuptime() went backwards (2282.963256 -> 2282,939227)
microuptime() went backwards (2283.001962 -> 2282,981795)
microuptime() went backwards (2282.994786 -> 2282,985048)
microuptime() went backwards (2283.022286 -> 2283,005253)
microuptime() went backwards (2283.051298 -> 2283,006887)
microuptime() went backwards (2283.051298 -> 2283,026625)
microuptime() went backwards (2283.051298 -> 2283,011953)
microuptime() went backwards (2283.051298 -> 2283,029117)
microuptime() went backwards (2283.053362 -> 2283,021739)
microuptime() went backwards (2283.116173 -> 2283,112313)
microuptime() went backwards (2283.126311 -> 2283,124726)
microuptime() went backwards (2283.160043 -> 2283,125717)
microuptime() went backwards (2283.135682 -> 2283,-695246829)
calcru: negative time of 38040 usec for pid 87187 (cat)
microuptime() went backwards (2283.266938 -> 2283,247116)
microuptime() went backwards (2283.280998 -> 2283,-695112026)
microuptime() went backwards (2283.290384 -> 2283,272279)
microuptime() went backwards (2283.356616 -> 2283,-695049963)
microuptime() went backwards (2283.416154 -> 2283,388048)
microuptime() went backwards (2283.429159 -> 2283,379383)
microuptime() went backwards (2283.429159 -> 2283,398693)
microuptime() went backwards (2283.429159 -> 2283,418003)
microuptime() went backwards (2283.429159 -> 2283,402901)
microuptime() went backwards (2283.429159 -> 2283,420065)
microuptime() went backwards (2283.429159 -> 2283,400244)
microuptime() went backwards (2283.429159 -> 2283,421913)
microuptime() went backwards (2283.429159 -> 2283,412605)
microuptime() went backwards (2283.485732 -> 2283,459343)
microuptime() went backwards (2283.523791 -> 2283,505042)
microuptime() went backwards (2283.528644 -> 2283,-694867599)
microuptime() went backwards (2283.539514 -> 2283,518190)
microuptime() went backwards (2283.554138 -> 2283,-694836740)
microuptime() went backwards (2283.573214 -> 2283,567982)
microuptime() went backwards (2283.643096 -> 2283,624991)
microuptime() went backwards (2283.688742 -> 2283,664070)
microuptime() went backwards (2283.675677 -> 2283,656285)
microuptime() went backwards (2283.689951 -> 2283,678711)
microuptime() went backwards (2283.769625 -> 2283,729075)
microuptime() went backwards (2283.788304 -> 2283,763631)
microuptime() went backwards (2283.804098 -> 2283,754323)
microuptime() went backwards (2283.804098 -> 2283,773418)
microuptime() went backwards (2283.804098 -> 2283,792298)
microuptime() went backwards (2283.804098 -> 2283,775909)
microuptime() went backwards (2283.804098 -> 2283,792645)
microuptime() went backwards (2283.804098 -> 2283,772179)
microuptime() went backwards (2283.804098 -> 2283,793849)
microuptime() went backwards (2283.804098 -> 2283,783038)
microuptime() went backwards (2283.804098 -> 2283,801704)
microuptime() went backwards (2283.835526 -> 2283,813213)
microuptime() went backwards (2283.835526 -> 2283,815920)
microuptime() went backwards (2283.835526 -> 2283,832144)
microuptime() went backwards (2283.850714 -> 2283,-694534586)
microuptime() went backwards (2283.866508 -> 2283,-694535312)
microuptime() went backwards (2283.866508 -> 2283,-694532519)
microuptime() went backwards (2283.855488 -> 2283,855405)
calcru: negative time of 0 usec for pid 87191 (cat)
microuptime() went backwards (2283.890163 -> 2283,889654)
microuptime() went backwards (2283.905021 -> 2283,901721)
microuptime() went backwards (2283.943260 -> 2283,929315)
microuptime() went backwards (2283.953263 -> 2283,915718)
microuptime() went backwards (2283.924944 -> 2283,910056)
microuptime() went backwards (2283.956940 -> 2283,-694433080)
microuptime() went backwards (2283.992403 -> 2283,964297)
microuptime() went backwards (2284.012825 -> 2283,985363)
microuptime() went backwards (2284.017261 -> 2283,987010)
microuptime() went backwards (2284.010372 -> 2283,-694385441)
microuptime() went backwards (2284.058304 -> 2284,027410)
microuptime() went backwards (2284.049530 -> 2284,029708)
microuptime() went backwards (2284.065468 -> 2284,-695329916)
microuptime() went backwards (2284.152465 -> 2284,131141)
microuptime() went backwards (2284.208013 -> 2284,189693)
microuptime() went backwards (2284.236596 -> 2284,191970)
microuptime() went backwards (2284.236596 -> 2284,211709)
microuptime() went backwards (2284.251318 -> 2284,204546)
microuptime() went backwards (2284.251318 -> 2284,230721)
microuptime() went backwards (2284.262177 -> 2284,233642)
microuptime() went backwards (2284.262177 -> 2284,252737)
microuptime() went backwards (2284.255455 -> 2284,246577)
microuptime() went backwards (2284.271465 -> 2284,261300)
microuptime() went backwards (2284.289000 -> 2284,-695094154)
microuptime() went backwards (2284.289000 -> 2284,287550)
microuptime() went backwards (2284.340166 -> 2284,320773)
microuptime() went backwards (2284.401962 -> 2284,364203)
microuptime() went backwards (2284.372273 -> 2284,369836)
microuptime() went backwards (2284.432402 -> 2284,412884)
microuptime() went backwards (2284.441501 -> 2284,434981)
calcru: negative time of 564 usec for pid 87194 (cat)
microuptime() went backwards (2284.476013 -> 2284,463271)
calcru: negative time of 9146 usec for pid 87195 (cat)
microuptime() went backwards (2284.521896 -> 2284,492420)
microuptime() went backwards (2284.521896 -> 2284,505297)
microuptime() went backwards (2284.514309 -> 2284,501996)
calcru: negative time of 0 usec for pid 87197 (cat)
microuptime() went backwards (2284.556199 -> 2284,531312)
microuptime() went backwards (2284.556199 -> 2284,552982)
microuptime() went backwards (2284.572422 -> 2284,535735)
microuptime() went backwards (2284.572422 -> 2284,543248)
microuptime() went backwards (2284.604111 -> 2284,566137)
microuptime() went backwards (2284.604111 -> 2284,590814)
microuptime() went backwards (2284.622616 -> 2284,583140)
microuptime() went backwards (2284.622616 -> 2284,599663)
microuptime() went backwards (2284.641335 -> 2284,605724)
microuptime() went backwards (2284.631899 -> 2284,611005)
microuptime() went backwards (2284.631899 -> 2284,629456)
microuptime() went backwards (2284.663916 -> 2284,610711)
microuptime() went backwards (2284.636458 -> 2284,626720)
calcru: negative time of 0 usec for pid 87204 (cat)
microuptime() went backwards (2284.693497 -> 2284,655738)
microuptime() went backwards (2284.693497 -> 2284,-694720158)
microuptime() went backwards (2284.707243 -> 2284,671843)
microuptime() went backwards (2284.707243 -> 2284,693731)
microuptime() went backwards (2284.700812 -> 2284,679059)
microuptime() went backwards (2284.700812 -> 2284,697296)
microuptime() went backwards (2284.733902 -> 2284,686061)
microuptime() went backwards (2284.711807 -> 2284,692200)
microuptime() went backwards (2284.711807 -> 2284,711295)
microuptime() went backwards (2284.750046 -> 2284,705852)
microuptime() went backwards (2284.732028 -> 2284,710919)
microuptime() went backwards (2284.732028 -> 2284,728941)
microuptime() went backwards (2284.786624 -> 2284,748864)
microuptime() went backwards (2284.786624 -> 2284,768177)
microuptime() went backwards (2284.803924 -> 2284,772385)
microuptime() went backwards (2284.803924 -> 2284,790837)
microuptime() went backwards (2284.810063 -> 2284,773376)
microuptime() went backwards (2284.810063 -> 2284,784751)
microuptime() went backwards (2284.819639 -> 2284,788959)
microuptime() went backwards (2284.819639 -> 2284,807410)
microuptime() went backwards (2284.826636 -> 2284,788876)
microuptime() went backwards (2284.826636 -> 2284,813083)
microuptime() went backwards (2284.826636 -> 2284,808068)
microuptime() went backwards (2284.851323 -> 2284,820858)
microuptime() went backwards (2284.851323 -> 2284,839095)
microuptime() went backwards (2284.858321 -> 2284,823136)
microuptime() went backwards (2284.858321 -> 2284,835798)
microuptime() went backwards (2284.870471 -> 2284,838718)
microuptime() went backwards (2284.870471 -> 2284,856955)
microuptime() went backwards (2284.876181 -> 2284,838851)
microuptime() went backwards (2284.876181 -> 2284,860095)
microuptime() went backwards (2284.923488 -> 2284,885728)
microuptime() went backwards (2284.923488 -> 2284,907616)
microuptime() went backwards (2284.934483 -> 2284,898010)
microuptime() went backwards (2284.934483 -> 2284,910672)
microuptime() went backwards (2284.945775 -> 2284,914451)
microuptime() went backwards (2284.945775 -> 2284,932259)
microuptime() went backwards (2284.941270 -> 2284,922737)
microuptime() went backwards (2284.941270 -> 2284,940548)
microuptime() went backwards (2284.998108 -> 2284,966355)
microuptime() went backwards (2284.998108 -> 2284,988240)
microuptime() went backwards (2285.007680 -> 2284,973997)
microuptime() went backwards (2285.007680 -> 2284,991165)
microuptime() went backwards (2285.009319 -> 2284,983705)
microuptime() went backwards (2285.009319 -> 2284,992719)
microuptime() went backwards (2285.017393 -> 2284,995855)
microuptime() went backwards (2285.017393 -> 2285,014092)
microuptime() went backwards (2285.050912 -> 2285,005860)
microuptime() went backwards (2285.032679 -> 2285,010712)
microuptime() went backwards (2285.032679 -> 2285,028734)
microuptime() went backwards (2285.082639 -> 2285,044665)
microuptime() went backwards (2285.082639 -> 2285,068698)
microuptime() went backwards (2285.094921 -> 2285,056089)
microuptime() went backwards (2285.094921 -> 2285,064460)
microuptime() went backwards (2285.116175 -> 2285,-695294143)
microuptime() went backwards (2285.116175 -> 2285,101590)
microuptime() went backwards (2285.118886 -> 2285,091985)
microuptime() went backwards (2285.118886 -> 2285,100141)
microuptime() went backwards (2285.125458 -> 2285,104135)
microuptime() went backwards (2285.125458 -> 2285,123444)
microuptime() went backwards (2285.161981 -> 2285,118216)
microuptime() went backwards (2285.151472 -> 2285,130363)
microuptime() went backwards (2285.151472 -> 2285,148600)
microuptime() went backwards (2285.157611 -> 2285,134357)
microuptime() went backwards (2285.157611 -> 2285,145303)
microuptime() went backwards (2285.170405 -> 2285,148867)
microuptime() went backwards (2285.170405 -> 2285,167319)
microuptime() went backwards (2285.203924 -> 2285,156727)
microuptime() went backwards (2285.181829 -> 2285,160506)
microuptime() went backwards (2285.181829 -> 2285,179601)
microuptime() went backwards (2285.214919 -> 2285,209559)
microuptime() went backwards (2285.237927 -> 2285,201884)
microuptime() went backwards (2285.237927 -> 2285,223518)
microuptime() went backwards (2285.261327 -> 2285,222283)
microuptime() went backwards (2285.272190 -> 2285,238721)
microuptime() went backwards (2285.272190 -> 2285,252667)
microuptime() went backwards (2285.281333 -> 2285,237136)
microuptime() went backwards (2285.281333 -> 2285,268032)
microuptime() went backwards (2285.281333 -> 2285,240056)
microuptime() went backwards (2285.281333 -> 2285,271596)
microuptime() went backwards (2285.303695 -> 2285,272586)
microuptime() went backwards (2285.303695 -> 2285,291681)
microuptime() went backwards (2285.303695 -> 2285,291169)
microuptime() went backwards (2285.311254 -> 2285,296153)
microuptime() went backwards (2285.346409 -> 2285,308650)
microuptime() went backwards (2285.346409 -> 2285,311013)
microuptime() went backwards (2285.339121 -> 2285,328739)
microuptime() went backwards (2285.351267 -> 2285,328871)
microuptime() went backwards (2285.351267 -> 2285,337028)
microuptime() went backwards (2285.378353 -> 2285,354539)
microuptime() went backwards (2285.387925 -> 2285,356173)
microuptime() went backwards (2285.387925 -> 2285,359180)
microuptime() went backwards (2285.409863 -> 2285,377038)
microuptime() went backwards (2285.409863 -> 2285,-694997784)
microuptime() went backwards (2285.429831 -> 2285,403442)
microuptime() went backwards (2285.436614 -> 2285,403145)
microuptime() went backwards (2285.436614 -> 2285,407654)
microuptime() went backwards (2285.444260 -> 2285,417442)
microuptime() went backwards (2285.444260 -> 2285,437610)
microuptime() went backwards (2285.456621 -> 2285,425727)
microuptime() went backwards (2285.456621 -> 2285,434098)
microuptime() went backwards (2285.468986 -> 2285,437233)
microuptime() went backwards (2285.468986 -> 2285,456114)
microuptime() went backwards (2285.475125 -> 2285,435864)
microuptime() went backwards (2285.465739 -> 2285,462869)
microuptime() went backwards (2285.522860 -> 2285,494111)
microuptime() went backwards (2285.522860 -> 2285,512777)
microuptime() went backwards (2285.531788 -> 2285,494243)
microuptime() went backwards (2285.531788 -> 2285,497036)
microuptime() went backwards (2285.523855 -> 2285,509612)
microuptime() went backwards (2285.531711 -> 2285,506955)
microuptime() went backwards (2285.531711 -> 2285,530089)
microuptime() went backwards (2285.531711 -> 2285,527003)
microuptime() went backwards (2285.593832 -> 2285,567574)
microuptime() went backwards (2285.593832 -> 2285,576803)
microuptime() went backwards (2285.603408 -> 2285,585303)
microuptime() went backwards (2285.605900 -> 2285,579427)
microuptime() went backwards (2285.605952 -> 2285,602222)
calcru: negative time of 33521 usec for pid 87247 (cat)
microuptime() went backwards (2285.638267 -> 2285,637114)
microuptime() went backwards (2285.671788 -> 2285,644541)
microuptime() went backwards (2285.671788 -> 2285,663207)
microuptime() went backwards (2285.682432 -> 2285,645102)
microuptime() went backwards (2285.682432 -> 2285,647596)
microuptime() went backwards (2285.672699 -> 2285,652877)
microuptime() went backwards (2285.672699 -> 2285,671758)
microuptime() went backwards (2285.708792 -> 2285,701072)
microuptime() went backwards (2285.730299 -> 2285,719534)
microuptime() went backwards (2285.730299 -> 2285,723399)
microuptime() went backwards (2285.719587 -> 2285,718649)
calcru: negative time of 131 usec for pid 87252 (cat)
microuptime() went backwards (2285.753378 -> 2285,752007)
calcru: negative time of 1207 usec for pid 87253 (cat)
microuptime() went backwards (2285.818362 -> 2285,797981)
microuptime() went backwards (2285.818362 -> 2285,-694575206)
microuptime() went backwards (2285.833183 -> 2285,822802)
microuptime() went backwards (2285.855115 -> 2285,830444)
microuptime() went backwards (2285.855115 -> 2285,826075)
microuptime() went backwards (2285.853324 -> 2285,842513)
microuptime() went backwards (2285.863754 -> 2285,848867)
microuptime() went backwards (2285.896851 -> 2285,875826)
microuptime() went backwards (2285.911787 -> 2285,886471)
microuptime() went backwards (2285.894545 -> 2285,887382)
calcru: negative time of 4641 usec for pid 87258 (cat)
microuptime() went backwards (2285.936861 -> 2285,906186)
microuptime() went backwards (2285.944508 -> 2285,925413)
microuptime() went backwards (2285.968977 -> 2285,941306)
microuptime() went backwards (2285.992204 -> 2285,966245)
microuptime() went backwards (2285.992204 -> 2285,957156)
microuptime() went backwards (2285.985477 -> 2285,973808)
microuptime() went backwards (2285.996122 -> 2285,982308)
calcru: negative time of 30224 usec for pid 87262 (cat)
microuptime() went backwards (2286.014760 -> 2286,000518)
microuptime() went backwards (2286.066010 -> 2286,040265)
microuptime() went backwards (2286.066010 -> 2286,061044)
calcru: negative time of 1848 usec for pid 87264 (cat)
microuptime() went backwards (2286.097054 -> 2286,067453)
microuptime() went backwards (2286.094752 -> 2286,080723)
microuptime() went backwards (2286.112691 -> 2286,107460)
microuptime() went backwards (2286.132913 -> 2286,112448)
microuptime() went backwards (2286.162494 -> 2286,151040)
microuptime() went backwards (2286.177001 -> 2286,164689)
microuptime() went backwards (2286.193539 -> 2286,184660)
microuptime() went backwards (2286.210620 -> 2286,198094)
microuptime() went backwards (2286.210620 -> 2286,205312)
microuptime() went backwards (2286.256639 -> 2286,232825)
microuptime() went backwards (2286.256639 -> 2286,233821)
microuptime() went backwards (2286.261927 -> 2286,251760)
microuptime() went backwards (2286.272786 -> 2286,260260)
microuptime() went backwards (2286.272786 -> 2286,256535)
microuptime() went backwards (2286.311592 -> 2286,287349)
microuptime() went backwards (2286.319019 -> 2286,295634)
microuptime() went backwards (2286.319019 -> 2286,-695085491)
microuptime() went backwards (2286.319250 -> 2286,308225)
microuptime() went backwards (2286.330109 -> 2286,317369)
microuptime() went backwards (2286.365562 -> 2286,334882)
microuptime() went backwards (2286.365562 -> 2286,356123)
microuptime() went backwards (2286.375563 -> 2286,340593)
microuptime() went backwards (2286.375563 -> 2286,341589)
microuptime() went backwards (2286.374549 -> 2286,365670)
calcru: negative time of 6923 usec for pid 87275 (cat)
microuptime() went backwards (2286.398554 -> 2286,395039)
microuptime() went backwards (2286.441269 -> 2286,433676)
microuptime() went backwards (2286.469637 -> 2286,448398)
microuptime() went backwards (2286.455186 -> 2286,447379)
calcru: negative time of 9577 usec for pid 87277 (cat)
microuptime() went backwards (2286.499433 -> 2286,490643)
calcru: negative time of 1204 usec for pid 87278 (cat)
microuptime() went backwards (2286.526011 -> 2286,509283)
calcru: negative time of 31202 usec for pid 87279 (cat)
microuptime() went backwards (2286.541476 -> 2286,528950)
microuptime() went backwards (2286.557837 -> 2286,539517)
microuptime() went backwards (2286.589425 -> 2286,582566)
microuptime() went backwards (2286.582270 -> 2286,574248)
microuptime() went backwards (2286.595704 -> 2286,582319)
microuptime() went backwards (2286.595704 -> 2286,584257)
calcru: negative time of 1634 usec for pid 87282 (cat)
microuptime() went backwards (2286.632797 -> 2286,632076)
microuptime() went backwards (2286.683495 -> 2286,669335)
microuptime() went backwards (2286.683495 -> 2286,645651)
microuptime() went backwards (2286.702210 -> 2286,655224)
microuptime() went backwards (2286.702210 -> 2286,679257)
microuptime() went backwards (2286.702210 -> 2286,672952)
microuptime() went backwards (2286.722001 -> 2286,676517)
microuptime() went backwards (2286.722001 -> 2286,699045)
microuptime() went backwards (2286.722001 -> 2286,683943)
microuptime() went backwards (2286.722001 -> 2286,702609)
microuptime() went backwards (2286.736854 -> 2286,704457)
microuptime() went backwards (2286.736854 -> 2286,699653)
microuptime() went backwards (2286.748931 -> 2286,735975)
microuptime() went backwards (2286.760220 -> 2286,739755)
microuptime() went backwards (2286.779191 -> 2286,774173)
calcru: negative time of 11213 usec for pid 87285 (cat)
microuptime() went backwards (2286.795414 -> 2286,783961)
calcru: negative time of 34513 usec for pid 87286 (cat)
microuptime() went backwards (2286.842406 -> 2286,833313)
microuptime() went backwards (2286.870650 -> 2286,854690)
microuptime() went backwards (2286.877862 -> 2286,855252)
microuptime() went backwards (2286.920409 -> 2286,905311)
microuptime() went backwards (2286.921843 -> 2286,911676)
microuptime() went backwards (2286.988374 -> 2286,961127)
microuptime() went backwards (2286.988374 -> 2286,982797)
microuptime() went backwards (2287.002237 -> 2286,980355)
microuptime() went backwards (2287.002237 -> 2286,966973)
microuptime() went backwards (2286.993792 -> 2286,977188)
microuptime() went backwards (2287.017468 -> 2287,013952)
calcru: negative time of 695448312 usec for pid 87291 (cat)
microuptime() went backwards (2287.036051 -> 2287,035110)
microuptime() went backwards (2287.050267 -> 2287,048253)
calcru: negative time of 22238 usec for pid 87292 (cat)
microuptime() went backwards (2287.069709 -> 2287,057611)
microuptime() went backwards (2287.069709 -> 2287,065557)
microuptime() went backwards (2287.093878 -> 2287,081565)
microuptime() went backwards (2287.103449 -> 2287,093712)
microuptime() went backwards (2287.103449 -> 2287,-695292909)
microuptime() went backwards (2287.121917 -> 2287,112394)
microuptime() went backwards (2287.144493 -> 2287,124112)
microuptime() went backwards (2287.144493 -> 2287,115665)
microuptime() went backwards (2287.141625 -> 2287,122018)
microuptime() went backwards (2287.141625 -> 2287,140899)
microuptime() went backwards (2287.179650 -> 2287,173435)
microuptime() went backwards (2287.191589 -> 2287,172923)
microuptime() went backwards (2287.171478 -> 2287,169463)
calcru: negative time of 6658 usec for pid 87297 (cat)
microuptime() went backwards (2287.190919 -> 2287,179465)
microuptime() went backwards (2287.239856 -> 2287,220333)
microuptime() went backwards (2287.239856 -> 2287,-695176554)
microuptime() went backwards (2287.243423 -> 2287,243133)
microuptime() went backwards (2287.268796 -> 2287,247127)
microuptime() went backwards (2287.279655 -> 2287,259489)
microuptime() went backwards (2287.279655 -> 2287,267354)
microuptime() went backwards (2287.309024 -> 2287,294651)
microuptime() went backwards (2287.309024 -> 2287,301309)
microuptime() went backwards (2287.284276 -> 2287,283121)
calcru: negative time of 0 usec for pid 87301 (cat)
calcru: negative time of 7742 usec for pid 87302 (cat)
microuptime() went backwards (2287.331546 -> 2287,319877)
microuptime() went backwards (2287.331546 -> 2287,322674)
microuptime() went backwards (2287.350781 -> 2287,344261)
microuptime() went backwards (2287.365931 -> 2287,352547)
microuptime() went backwards (2287.379505 -> 2287,367836)
microuptime() went backwards (2287.395513 -> 2287,386205)
microuptime() went backwards (2287.395513 -> 2287,395101)
microuptime() went backwards (2287.423422 -> 2287,411968)
microuptime() went backwards (2287.444282 -> 2287,422184)
microuptime() went backwards (2287.444282 -> 2287,419534)
microuptime() went backwards (2287.447641 -> 2287,438117)
microuptime() went backwards (2287.459787 -> 2287,447905)
microuptime() went backwards (2287.454480 -> 2287,450750)
calcru: negative time of 27090 usec for pid 87307 (cat)
microuptime() went backwards (2287.514175 -> 2287,489939)
microuptime() went backwards (2287.531825 -> 2287,508655)
microuptime() went backwards (2287.531825 -> 2287,517975)
microuptime() went backwards (2287.542994 -> 2287,522318)
microuptime() went backwards (2287.542994 -> 2287,521377)
microuptime() went backwards (2287.576433 -> 2287,533309)
microuptime() went backwards (2287.576433 -> 2287,563990)
microuptime() went backwards (2287.591369 -> 2287,554038)
microuptime() went backwards (2287.591369 -> 2287,575922)
microuptime() went backwards (2287.591369 -> 2287,565970)
microuptime() went backwards (2287.591369 -> 2287,584636)
microuptime() went backwards (2287.591369 -> 2287,567397)
microuptime() went backwards (2287.582203 -> 2287,572680)
microuptime() went backwards (2287.596280 -> 2287,594267)
microuptime() went backwards (2287.596280 -> 2287,596122)
microuptime() went backwards (2287.624872 -> 2287,614490)
microuptime() went backwards (2287.635731 -> 2287,626638)
microuptime() went backwards (2287.637252 -> 2287,634380)
calcru: negative time of 33917 usec for pid 87311 (cat)
microuptime() went backwards (2287.656049 -> 2287,647600)
microuptime() went backwards (2287.656049 -> 2287,653532)
microuptime() went backwards (2287.682282 -> 2287,671042)
microuptime() went backwards (2287.693141 -> 2287,681258)
calcru: negative time of 14647 usec for pid 87313 (cat)
microuptime() went backwards (2287.741876 -> 2287,729778)
microuptime() went backwards (2287.760691 -> 2287,758677)
calcru: negative time of 5800 usec for pid 87315 (cat)
microuptime() went backwards (2287.779918 -> 2287,767821)
microuptime() went backwards (2287.779918 -> 2287,773193)
microuptime() went backwards (2287.821599 -> 2287,784613)
calcru: negative time of 0 usec for pid 87316 (cat)
microuptime() went backwards (2287.802636 -> 2287,794830)
microuptime() went backwards (2287.836591 -> 2287,823850)
microuptime() went backwards (2287.851098 -> 2287,841361)
microuptime() went backwards (2287.873778 -> 2287,856323)
microuptime() went backwards (2287.885288 -> 2287,877052)
microuptime() went backwards (2287.898722 -> 2287,885981)
microuptime() went backwards (2287.891915 -> 2287,891617)
calcru: negative time of 15375 usec for pid 87320 (cat)
microuptime() went backwards (2287.913073 -> 2287,903336)
microuptime() went backwards (2287.927505 -> 2287,919912)
microuptime() went backwards (2287.969997 -> 2287,965416)
microuptime() went backwards (2288.008374 -> 2287,988851)
calcru: negative time of 15077 usec for pid 87323 (cat)
microuptime() went backwards (2288.004571 -> 2287,994190)
microuptime() went backwards (2288.052902 -> 2288,030160)
microuptime() went backwards (2288.052902 -> 2288,009694)
calcru: negative time of 8599 usec for pid 87325 (cat)
microuptime() went backwards (2288.101804 -> 2288,053966)
microuptime() went backwards (2288.082716 -> 2288,071905)
microuptime() went backwards (2288.093790 -> 2288,080191)
microuptime() went backwards (2288.121526 -> 2288,110930)
microuptime() went backwards (2288.147749 -> 2288,130586)
microuptime() went backwards (2288.147749 -> 2288,140894)
calcru: negative time of 27340 usec for pid 87328 (cat)
microuptime() went backwards (2288.162358 -> 2288,154123)
calcru: negative time of 12717 usec for pid 87329 (cat)
microuptime() went backwards (2288.182288 -> 2288,178559)
microuptime() went backwards (2288.214101 -> 2288,205221)
microuptime() went backwards (2288.241182 -> 2288,221660)
microuptime() went backwards (2288.241182 -> 2288,223599)
calcru: negative time of 31417 usec for pid 87331 (cat)
microuptime() went backwards (2288.266008 -> 2288,243267)
microuptime() went backwards (2288.266008 -> 2288,-695144601)
microuptime() went backwards (2288.271085 -> 2288,262420)
microuptime() went backwards (2288.294519 -> 2288,271563)
microuptime() went backwards (2288.294519 -> 2288,275134)
calcru: negative time of 1419 usec for pid 87333 (cat)
microuptime() went backwards (2288.362908 -> 2288,344887)
microuptime() went backwards (2288.362908 -> 2288,348850)
microuptime() went backwards (2288.393310 -> 2288,371213)
microuptime() went backwards (2288.393310 -> 2288,373498)
microuptime() went backwards (2288.412248 -> 2288,391008)
microuptime() went backwards (2288.423322 -> 2288,403370)
microuptime() went backwards (2288.423322 -> 2288,409732)
microuptime() went backwards (2288.418446 -> 2288,409137)
microuptime() went backwards (2288.431450 -> 2288,419568)
m
machdep.msgbuf_clear: 0
machdep.uc_devlist: ^F
machdep.i8254_freq: 1193182
machdep.cs_recv_delay: 570
machdep.wi_cache_mcastonly: 0
machdep.wi_cache_iponly: 1
machdep.conspeed: 9600
user.cs_path: /usr/bin:/bin:/usr/sbin:/sbin:
user.bc_base_max: 99
user.bc_dim_max: 2048
user.bc_scale_max: 99
user.bc_string_max: 1000
user.coll_weights_max: 0
user.expr_nest_max: 32
user.line_max: 2048
user.re_dup_max: 255
user.posix2_version: 199212
user.posix2_c_bind: 0
user.posix2_c_dev: 0
user.posix2_char_term: 0
user.posix2_fort_dev: 0
user.posix2_fort_run: 0
user.posix2_localedef: 0
user.posix2_sw_dev: 0
user.posix2_upe: 0
user.stream_max: 20
user.tzname_max: 255
p1003_1b.asynchronous_io: 0
p1003_1b.mapped_files: 0
p1003_1b.memlock: 0
p1003_1b.memlock_range: 0
p1003_1b.memory_protection: 0
p1003_1b.message_passing: 0
p1003_1b.prioritized_io: 0
p1003_1b.priority_scheduling: 1
p1003_1b.realtime_signals: 0
p1003_1b.semaphores: 0
p1003_1b.fsync: 0
p1003_1b.shared_memory_objects: 0
p1003_1b.synchronized_io: 0
p1003_1b.timers: 0
p1003_1b.aio_listio_max: 0
p1003_1b.aio_max: 0
p1003_1b.aio_prio_delta_max: 0
p1003_1b.delaytimer_max: 0
p1003_1b.mq_open_max: 0
p1003_1b.pagesize: 4096
p1003_1b.rtsig_max: 0
p1003_1b.sem_nsems_max: 0
p1003_1b.sem_value_max: 0
p1003_1b.sigqueue_max: 0
p1003_1b.timer_max: 0
jail.set_hostname_allowed: 1
>How-To-Repeat:
I'm not entirely sure, but I believe you can do it like so:
Get any motherboard with the KX133 chipset by VIA (I've seen many reports for Epox boards, and I run an A-bit KA7 myself).
Cause your UDMA hard drive some stress by doing lots of IO/seeking.
Sooner or later, you'll get the messages like mad.
>Fix:
None that I know of. I flashed the BIOS to the latest one offerred by A-bit, disabled Ultra DMA in the BIOS (FreeBSD still uses UDMA regardless). None of it helped.
>Release-Note:
>Audit-Trail:
>Unformatted:
To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-bugs" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20000528103357.00C3837B51C>