[freebsd] problème "calcru" et bizarrerie cpu

Le
patpro ~ Patrick Proniewski
Bonjour,

Hier, j'ai vu que mon serveur (FreeBSD 8.1, amd64, xeon 4-core) a montré
des symptômes étranges :

21:09:09 rack kernel: calcru: runtime went backwards from 122407344 usec
to 108865844 usec for pid 2 (g_event)
21:09:09 rack kernel: calcru: runtime went backwards from 3293977567
usec to 2931366351 usec for pid 12 (intr)
21:09:09 rack kernel: calcru: runtime went backwards from 18251116899775
usec to 16234132245032 usec for pid 11 (idle)
21:09:09 rack kernel: calcru: runtime went backwards from 3170254 usec
to 2819879 usec for pid 1 (init)
21:09:09 rack kernel: calcru: runtime went backwards from 96474895886
usec to 85798170025 usec for pid 1 (init)
21:09:09 rack kernel: calcru: runtime went backwards from 11274704347
usec to 10074917545 usec for pid 0 (kernel)


entre 21:08:23 et 21:10:30, j'ai lancé un binaire linux (le client
steam), qui a scanné plusieurs Go de fichiers sur un volume ZFS
compressé. Le volume ZFS est un disque SATA accédé via une carte raid
3Ware.

Je ne sais pas trop comment ça a pu jouer trop d'interrupt ? ZFS
saturé ? Pendant l'exécution de la commande en tout cas, top ne montrait
rien d'anormal.

Quelques minutes plus tard, j'ai lancé le serveur dédié du jeu (mis à
jour par la commande précédente). Il s'est avéré injouable, comme si le
serveur avait du retard sur l'envoi de paquets à destination des
joueurs, ou des grosses latences de manière générale.

Quelques heures plus tôt, environ vers 19h30, le monitoring de cette
machine a commencé à reporter un usage CPU anormal : inférieur à 400%,
idle inclus. Voir graph : <http://patpro.net/~patpro/cpu-day.png>

Je soupçonne un problème de type "économie d'énergie", mais je ne
comprends pas comment il a pu se déclencher subitement, sans aucune
intervention (ACPI n'est pas configuré pour, en plus). Personne n'était
connecté à la machine à ce moment là, ou dans les heures avant.

En parallèle, la température des cores du CPU a grimpé légèrement :
<http://patpro.net/~patpro/cputemp-day.png>. Comme je suis en
datacenter, je pars du principe que la température de l'air est
relativement constante (le graph mensuel est cohérent avec cette
hypothèse).

Je ne sais pas si tout est lié, mais toute idée est la bienvenue.


patpro
--

dmesg.boot :

Copyright (c) 1992-2010 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.1-RELEASE #0: Mon Jul 19 02:36:49 UTC 2010
root@mason.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC amd64
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Xeon(R) CPU E5450 @ 3.00GHz (3000.01-MHz
K8-class CPU)
Origin = "GenuineIntel" Id = 0x1067a Family = 6 Model = 17
Stepping = 10

Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,
MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>

Features2=0x40ce3bd<SSE3,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PD
CM,DCA,SSE4.1,XSAVE>
AMD Features=0x20100800<SYSCALL,NX,LM>
AMD Features2=0x1<LAHF>
TSC: P-state invariant
real memory = 17179869184 (16384 MB)
avail memory = 16562405376 (15795 MB)
ACPI APIC Table: <PTLTD APIC >
FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs
FreeBSD/SMP: 1 package(s) x 4 core(s)
cpu0 (BSP): APIC ID: 0
cpu1 (AP): APIC ID: 1
cpu2 (AP): APIC ID: 2
cpu3 (AP): APIC ID: 3
ioapic0 <Version 2.0> irqs 0-23 on motherboard
kbd1 at kbdmux0
acpi0: <PTLTD XSDT> on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
unknown: I/O range not supported
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
cpu0: <ACPI CPU> on acpi0
cpu1: <ACPI CPU> on acpi0
cpu2: <ACPI CPU> on acpi0
cpu3: <ACPI CPU> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <ACPI PCI-PCI bridge> at device 2.0 on pci0
pci1: <ACPI PCI bus> on pcib1
pcib2: <ACPI PCI-PCI bridge> at device 4.0 on pci0
pci2: <ACPI PCI bus> on pcib2
3ware device driver for 9000 series storage controllers, version:
3.70.05.001
twa0: <3ware 9000 series Storage Controller> port 0x2000-0x20ff mem
0xf8000000-0xf9ffffff,0xfc100000-0xfc100fff irq 16 at device 0.0 on pci2
twa0: [ITHREAD]
twa0: INFO: (0x15: 0x1300): Controller details:: Model 9650SE-4LPML, 4
ports, Firmware FE9X 3.08.00.016, BIOS BE9X 3.08.00.004
pcib3: <ACPI PCI-PCI bridge> at device 6.0 on pci0
pci3: <ACPI PCI bus> on pcib3
pci0: <base peripheral> at device 8.0 (no driver attached)
uhci0: <Intel 82801I (ICH9) USB controller> port 0x1820-0x183f irq 20 at
device 26.0 on pci0
uhci0: [ITHREAD]
usbus0: <Intel 82801I (ICH9) USB controller> on uhci0
ehci0: <Intel 82801I (ICH9) USB 2.0 controller> mem
0xfc600000-0xfc6003ff irq 22 at device 26.7 on pci0
ehci0: [ITHREAD]
usbus1: EHCI version 1.0
usbus1: <Intel 82801I (ICH9) USB 2.0 controller> on ehci0
pcib4: <ACPI PCI-PCI bridge> irq 16 at device 28.0 on pci0
pci4: <ACPI PCI bus> on pcib4
pcib5: <ACPI PCI-PCI bridge> irq 16 at device 28.4 on pci0
pci5: <ACPI PCI bus> on pcib5
em0: <Intel(R) PRO/1000 Network Connection 7.0.5> port 0x3000-0x301f mem
0xfc200000-0xfc21ffff irq 16 at device 0.0 on pci5
em0: Using MSI interrupt
em0: [FILTER]
em0: Ethernet address: 00:30:48:d2:e3:fe
pcib6: <ACPI PCI-PCI bridge> irq 17 at device 28.5 on pci0
pci6: <ACPI PCI bus> on pcib6
em1: <Intel(R) PRO/1000 Network Connection 7.0.5> port 0x4000-0x401f mem
0xfc300000-0xfc31ffff irq 17 at device 0.0 on pci6
em1: Using MSI interrupt
em1: [FILTER]
em1: Ethernet address: 00:30:48:d2:e3:ff
uhci1: <Intel 82801I (ICH9) USB controller> port 0x1840-0x185f irq 23 at
device 29.0 on pci0
uhci1: [ITHREAD]
usbus2: <Intel 82801I (ICH9) USB controller> on uhci1
uhci2: <Intel 82801I (ICH9) USB controller> port 0x1860-0x187f irq 22 at
device 29.1 on pci0
uhci2: [ITHREAD]
usbus3: <Intel 82801I (ICH9) USB controller> on uhci2
uhci3: <Intel 82801I (ICH9) USB controller> port 0x1880-0x189f irq 21 at
device 29.2 on pci0
uhci3: [ITHREAD]
usbus4: <Intel 82801I (ICH9) USB controller> on uhci3
ehci1: <Intel 82801I (ICH9) USB 2.0 controller> mem
0xfc600400-0xfc6007ff irq 23 at device 29.7 on pci0
ehci1: [ITHREAD]
usbus5: EHCI version 1.0
usbus5: <Intel 82801I (ICH9) USB 2.0 controller> on ehci1
pcib7: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci7: <ACPI PCI bus> on pcib7
atapci0: <ITE IT8213F UDMA133 controller> port
0x5098-0x509f,0x5090-0x5093,0x5080-0x508f irq 17 at device 0.0 on pci7
atapci0: [ITHREAD]
ata2: <ATA channel 0> on atapci0
ata2: [ITHREAD]
vgapci0: <VGA-compatible display> port 0x5000-0x507f mem
0xfa000000-0xfbffffff,0xfc000000-0xfc03ffff at device 1.0 on pci7
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci1: <Intel ICH9 SATA300 controller> port
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x18d0-0x18df,0x18c0-0x18cf at
device 31.2 on pci0
ata0: <ATA channel 0> on atapci1
ata0: [ITHREAD]
ata1: <ATA channel 1> on atapci1
ata1: [ITHREAD]
pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
atapci2: <Intel ICH9 SATA300 controller> port
0x1c28-0x1c2f,0x1c1c-0x1c1f,0x1c20-0x1c27,0x1c18-0x1c1b,0x18f0-0x18ff,0x1
8e0-0x18ef irq 18 at device 31.5 on pci0
atapci2: [ITHREAD]
ata3: <ATA channel 0> on atapci2
ata3: [ITHREAD]
ata4: <ATA channel 1> on atapci2
ata4: [ITHREAD]
acpi_button0: <Power Button> on acpi0
atrtc0: <AT realtime clock> port 0x70-0x71 irq 8 on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
uart0: [FILTER]
uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
uart1: [FILTER]
fdc0: <floppy drive controller> port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on
acpi0
fdc0: [FILTER]
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
orm0: <ISA Option ROMs> at iomem 0xc0000-0xc7fff,0xc8000-0xc9fff on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
ppc0: cannot reserve I/O port range
est0: <Enhanced SpeedStep Frequency Control> on cpu0
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 91e091e0600091e
device_attach: est0 attach returned 6
p4tcc0: <CPU Frequency Thermal Control> on cpu0
est1: <Enhanced SpeedStep Frequency Control> on cpu1
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 91e091e0600091e
device_attach: est1 attach returned 6
p4tcc1: <CPU Frequency Thermal Control> on cpu1
est2: <Enhanced SpeedStep Frequency Control> on cpu2
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 91e091e0600091e
device_attach: est2 attach returned 6
p4tcc2: <CPU Frequency Thermal Control> on cpu2
est3: <Enhanced SpeedStep Frequency Control> on cpu3
est: CPU supports Enhanced Speedstep, but is not recognized.
est: cpu_vendor GenuineIntel, msr 91e091e0600091e
device_attach: est3 attach returned 6
p4tcc3: <CPU Frequency Thermal Control> on cpu3
Timecounters tick every 1.000 msec
usbus0: 12Mbps Full Speed USB v1.0
usbus1: 480Mbps High Speed USB v2.0
usbus2: 12Mbps Full Speed USB v1.0
usbus3: 12Mbps Full Speed USB v1.0
usbus4: 12Mbps Full Speed USB v1.0
usbus5: 480Mbps High Speed USB v2.0
ugen0.1: <Intel> at usbus0
uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
ugen1.1: <Intel> at usbus1
uhub1: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
ugen2.1: <Intel> at usbus2
uhub2: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
ugen3.1: <Intel> at usbus3
uhub3: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus3
ugen4.1: <Intel> at usbus4
uhub4: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus4
ugen5.1: <Intel> at usbus5
uhub5: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus5
uhub0: 2 ports with 2 removable, self powered
uhub2: 2 ports with 2 removable, self powered
uhub3: 2 ports with 2 removable, self powered
uhub4: 2 ports with 2 removable, self powered
uhub1: 2 ports with 2 removable, self powered
uhub5: 6 ports with 6 removable, self powered
da0 at twa0 bus 0 scbus0 target 0 lun 0
da0: <AMCC 9650SE-4LP DISK 3.08> Fixed Direct Access SCSI-5 device
da0: 100.000MB/s transfers
da0: 953664MB (1953103872 512 byte sectors: 255H 63S/T 121575C)
da1 at twa0 bus 0 scbus0 target 1 lun 0
da1: <AMCC 9650SE-4LP DISK 3.08> Fixed Direct Access SCSI-5 device
da1: 100.000MB/s transfers
da1: 1907338MB (3906228224 512 byte sectors: 255H 63S/T 243151C)
da2 at twa0 bus 0 scbus0 target 2 lun 0
da2: <AMCC 9650SE-4LP DISK 3.08> Fixed Direct Access SCSI-5 device
da2: 100.000MB/s transfers
da2: 1907338MB (3906228224 512 byte sectors: 255H 63S/T 243151C)
SMP: AP CPU #1 Launched!
SMP: AP CPU #2 Launched!
SMP: AP CPU #3 Launched!
Trying to mount root from ufs:/dev/da0s1a
ZFS filesystem version 3
ZFS storage pool version 14
em0: link state changed to UP

--
A vendre ! http://www.patpro.net/blog/index.php/2008/01/12/133
Vidéos High-Tech et Jeu Vidéo
Téléchargements
Vos réponses
Gagnez chaque mois un abonnement Premium avec GNT : Inscrivez-vous !
Trier par : date / pertinence
Philippe Chevalier
Le #22998211
On Wed, 05 Jan 2011 11:06:39 +0100, patpro ~ Patrick Proniewski
Bonjour,

Hier, j'ai vu que mon serveur (FreeBSD 8.1, amd64, xeon 4-core) a montré
des symptômes étranges :

21:09:09 rack kernel: calcru: runtime went backwards from 122407344 usec
to 108865844 usec for pid 2 (g_event)
21:09:09 rack kernel: calcru: runtime went backwards from 3293977567
usec to 2931366351 usec for pid 12 (intr)



Ca ressemble à un probleme de synchronisation d'horloge.

Quel est le timecounter utilisé par le kernel ?

Verifie :

sysctl kern.timecounter.choice
sysctl kern.timecounter.hardware

Il devrait te donner les différentes horloges disponibles et celle
utilisée actuellement.

Tu peux commencer par essayer avec TSC, puis i8254, puisqu'il a l'air
d'utiliser ACPI-Safe par défaut, qui est celle avec la fréquence la plus
élevée, mais pas forcément la plus sure.


K.
--
Kyoko Otonashi's shrine / Le temple de Kyoko Otonashi
My tribute to Maison Ikkoku / Mon hommage a Maison Ikkoku
Visit http://www.kyoko.org/
patpro ~ Patrick Proniewski
Le #22998271
In article Philippe Chevalier
On Wed, 05 Jan 2011 11:06:39 +0100, patpro ~ Patrick Proniewski
> Bonjour,
>
> Hier, j'ai vu que mon serveur (FreeBSD 8.1, amd64, xeon 4-core) a montrÈ
> des symptÙmes Ètranges :
>
> 21:09:09 rack kernel: calcru: runtime went backwards from 122407344 usec
> to 108865844 usec for pid 2 (g_event)
> 21:09:09 rack kernel: calcru: runtime went backwards from 3293977567
> usec to 2931366351 usec for pid 12 (intr)

Ca ressemble ý un probleme de synchronisation d'horloge.

Quel est le timecounter utilisÈ par le kernel ?

Verifie :

sysctl kern.timecounter.choice
sysctl kern.timecounter.hardware



kern.timecounter.choice: TSC(-100) ACPI-fast(1000) i8254(0)
dummy(-1000000)
kern.timecounter.hardware: ACPI-fast

que du part défaut en fait.
Mais ce qui m'étonne c'est que cela survienne d'un coup, avec hausse de
température des cores CPU, et semble-t-il désactivation sélective de
certains cores sous forte charge.
Ce n'est jamais arrivé avant, alors que j'ai fait un paquet de bench et
de CPU burn-tests.

Je soupçonne de plus en plus un souci de ventilation, mais il apparait
que la température des cores est redescendu à une valeur proche de
l'ancienne, apres 2 jours de "surchauffe" inexpliquée.

J'ai ouvert un fil sur les forums FreeBSD, où j'ai déjà échangé des info
complémentaires :

http://forums.freebsd.org/showthread.php?t 709

Tu peux commencer par essayer avec TSC, puis i8254, puisqu'il a l'air
d'utiliser ACPI-Safe par dÈfaut, qui est celle avec la frÈquence la plus
ÈlevÈe, mais pas forcÈment la plus sure.



j'aimerai autant être sûr que j'ai pas un problème matériel avant de
jouer avec la partie soft ;)

patpro

--
A vendre ! http://www.patpro.net/blog/index.php/2008/01/12/133
Philippe Chevalier
Le #22998391
n Fri, 07 Jan 2011 14:56:15 +0100, patpro ~ Patrick Proniewski

Je soupçonne de plus en plus un souci de ventilation, mais il apparait
que la température des cores est redescendu à une valeur proche de
l'ancienne, apres 2 jours de "surchauffe" inexpliquée.



Surchauffe bof... 45° je trouve pas ca monstrueux. Pas de quoi throttler
une CPU AMHA. Et d'ailleurs, vu ton dmesg, je suis même pas sur que ca
soit activé. Il devrait y avoir une ligne genre <ACPI CPU Throttling> on
cpu0...

A voir si EIST et C1E sont activés dans ton bios ou pas.

K.
--
Kyoko Otonashi's shrine / Le temple de Kyoko Otonashi
My tribute to Maison Ikkoku / Mon hommage a Maison Ikkoku
Visit http://www.kyoko.org/
patpro ~ Patrick Proniewski
Le #22998481
In article Philippe Chevalier
n Fri, 07 Jan 2011 14:56:15 +0100, patpro ~ Patrick Proniewski
>
> Je soupÁonne de plus en plus un souci de ventilation, mais il apparait
> que la tempÈrature des cores est redescendu ý une valeur proche de
> l'ancienne, apres 2 jours de "surchauffe" inexpliquÈe.

Surchauffe bof... 45ƒ je trouve pas ca monstrueux. Pas de quoi throttler
une CPU AMHA. Et d'ailleurs, vu ton dmesg, je suis mÍme pas sur que ca
soit activÈ. Il devrait y avoir une ligne genre <ACPI CPU Throttling> on
cpu0...

A voir si EIST et C1E sont activÈs dans ton bios ou pas.



Normalement ils ne le sont pas. Mais je vais essayer de le faire
vérifier. La machine est à 400km.

Néanmoins, les températures que j'ai ne sont pas forcément fiables,
elles sortent du module coretemp.
Je me fie plus aux variations. J'avais 38°C de moyenne sur le mois, et
d'un seul coup, c'est passé à plus de 44, avec des pics au delà de 50.
Et surtout, mon utilisation CPU qui était constante à 400% idle inclus
s'est mise à faire le yoyo, avec des chutes à 200% idle inclus. Ça
équivaut à deux cores désactivés.

patpro

--
A vendre ! http://www.patpro.net/blog/index.php/2008/01/12/133
Publicité
Poster une réponse
Anonyme