* [Xenomai-help] Very high latencies under stress testing
@ 2010-08-13 14:17 edward.robbins
2010-08-13 14:35 ` Gilles Chanteperdrix
2010-08-13 14:40 ` Philippe Gerum
0 siblings, 2 replies; 38+ messages in thread
From: edward.robbins @ 2010-08-13 14:17 UTC (permalink / raw)
To: xenomai
[-- Attachment #1: Type: text/plain, Size: 6557 bytes --]
Hello all,
I have just set up my first xenomai system, and though I believe I have followed most of the guidelines, if I run latency it sits at around 8uS max, until I run something to stress the system (e.g. startx, or killing the x server) when it jumps to 700-800uS.
I wonder if this is to do with graphics? I have set "NoAccel" in the driver section of Xorg.conf (I am using fbdev). I also notice that latencies go massive (e.g. 4200uS) the first time I run glxgears. "glxinfo" reports "Direct rendering: no".
This is a core 2 duo system (MEN F19P cPCI) with ICH9M-SFF chipset. I am running debian (lenny) and have followed the guide in the wiki (here: http://www.xenomai.org/index.php/Building_Debian_packages) to install kernel 2.6.32.15 and xenomai 2.5.4. I have made the following selections for kernel configuration in order to try and prevent latency issues:
Processor type and features:
Enable interrupt pipeline
Enable high resolution timer support
Disable dell laptop support
Processor family --> Core 2/Newer Xeon
Preemption model --> Preemptible kernel (low latency desktop)
Bus options (PCI etc):
Disable PCI express hotplug driver
Disable message signalled interrupts (MSI and MSI-X)
Disable PCCard (PCMCIA/Cardbus support)
Disable support for PCI hotplug
Device drivers:
Disable Memory Technology Device (MTD) support
Disable Fusion MPT device support
Disable I20 device support
Disable ISDN support
Power management options (ACPUI, APM):
Disable ACPI (Advanced Configuration and Power Interface) Support --> Processor
Disable CPU Frequency Scaling
Disable CPU idle PM support
Disable Power Managment Support
Real-time sub-system:
Enable Machine--> SMI workaround
Enable Machine--> globally disable SMI
I have read through this: http://svn.gna.org/svn/xenomai/trunk/TROUBLESHOOTING and tried to find anything relevant. I am booting from an on board compact flash via USB. I wondered if this could be the problem. Output of hdparm:
hdparm -v /dev/sda
readonly = 0 (off)
readahead = 256 (on)
geometry = 1024/255/63, sectors = 31227840, start = 0
hdparm -acdgkmur /dev/sda
HDIO_GET_MULTICOUNT failed: Invalid argument
HDIO_GET_32BIT failed: Invalid argument
HDIO_GET_UNMASKINTR failed: Invalid argument
HDIO_GET_DMA failed: Invaid argument
HDIO_GET_KEEPSETTINGS failed: Invalid argument
(reast of output same as hdparm -v)
hdparm -t /dev/sda
/dev/sda:
Timing buffered disk reads: 100MB in 3.01 seconds = 33.24 MB/sec
hdparm -T /dev/sda
/dev/sda:
Timing cached reads: 11006 MB in 2.00 seconds = 5503.00 MB/sec
Then I did cat /proc/scsi/scsi:
Host: scsi4 Channel: 00 Id: 00 Lun: 00
Vendor: Generic Model: Flash HS-CF Rev: 1.68
Type: Direct-Access ANSI SCSI revision: 00
Also, this embedded system has a lot of configuration options in the BIOS (more than I have seen on any other system). Some seem like they could be very useful but are currently unusable (e.g. if I set "SMI handler" to off, the system will no longer boot from compact flash). There are also other options that might be relevant. I have tried playing with them, but am not even sure what some are and the manual is quite cryptic:
IDE Controller settings
"HDC configure as" Options: "IDE", "RAID", "AHCI"
USB Configuration
"USB Legacy" Enable/Disable
"EHCI1" Enable/Disable
"EHCI2" "
"UHCI1" "
"UHCI2"
...
"UHCI5"
"Per-Port Control2" Enable/Disable
"USB Pre-fetch Feature" Enable/Disable
"USB Pre-fetch Time" 2ms/4ms
"USB HC Alignment" Enable/Disable
Chipset Configuration
"CRID/SRID" Enable/Disable
"Port 80h Cycles" LPC bus/PCI bus
"DMI Link ASPM Control" Enable/Disable
"Automatic ASMO" Auto/Manual
"ASPM L0s Support" Enable/Disable
"ASPM L0sL1 Support" Enable/Disable
"VT-d" Enable/Disable
ACPI Table/Feature Control
"FACP - C2 Latency Value" Enable/Disable
"FACP - C3 Latency Value" Enable/Disable
"FACP - RTC S4 Wakeup" Enable/Disable
"APIC - IO APIC Mode" Enable/Disable
"HPET - HPET Support" Enable/Disable
PCI Express Root Port 1/2/3/4/5/6 Settings
"ASPM" Enable/Disable
"Automatic ASPM" Auto/Manual
"ASPM L0s" Root&Endpoint Ports/ Disabled/ Root Port Only/ Endpoint port Only
"ASPM L1" Enable/Disable
"URR" Enable/Disable
"FER" Enable/Disable
"NFER" Enable/Disable
"CER" Enable/Disable
"CTO" Enable/Disable
"SEFE" Enable/Disable
"SENFE" Enable/Disable
"SECE" Enable/Disable
"PME Interrupt" Enable/Disable
"PME SCI" Enable/Disable
"Hot Plug SCI" Enable/Disable
Advanced CPU Control
"P-States" Enable/Disable
"CMP Support" Enable/Disable
"Vanderpool Technology" Enable/Disable
"SMRR Support" Auto/Disable
"C-States" Enable/Disable
"Enhanced C-States" Enable/Disable
"C-State Pop Up Mode" Enable/Disable
"C-State Pop Down Mode" Enable/Disable
"C4 Exit Timing Mode" Fast/Slow/Default/Force Slow
"DeepC4" Enable/Disable
"Hard C4E" Enable/Disable
"Enable C6" Enable/Disable
"EMTTM" Enable/Disable
"Bi-directional PROCHOT#" Enable/Disable
"ACPI 3.0 T-States" Enable/Disable
"DTS" Enable/Disable"
... (lots more options that I am not sure what they really are for!)
Platfoirm Power Management
"Storage Break Event" Enable/Disable
"PCIE Break Event" Enable/Disable
"PCI Break Event" Enable/Disable
"EHCI Break Event" Enable/Disable
"UHCI Break Event" Enable/Disable
"HDA Break Event" Enable/Disable
"ACPI S3" Enable/Disable
So, could anyone suggest what I might try to improve the system? Sorry for the torrent of information... I thought it better to give as much info as I could think of than to not provide enough to make a diagnosis!
Thanks,
Edward Robbins
Control Systems Engineer
Oxford Technologies Ltd
UKAEA Culham
Joint European Torus, Remote Handling Division
[-- Attachment #2: Type: text/html, Size: 10582 bytes --]
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-08-13 14:17 [Xenomai-help] Very high latencies under stress testing edward.robbins
@ 2010-08-13 14:35 ` Gilles Chanteperdrix
2010-08-16 12:13 ` edward.robbins
2010-08-13 14:40 ` Philippe Gerum
1 sibling, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-08-13 14:35 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Hello all,
>
> I have just set up my first xenomai system, and though I believe I
> have followed most of the guidelines, if I run latency it sits at
> around 8uS max, until I run something to stress the system (e.g.
> startx, or killing the x server) when it jumps to 700-800uS.
>
> I wonder if this is to do with graphics? I have set "NoAccel" in the
> driver section of Xorg.conf (I am using fbdev). I also notice that
> latencies go massive (e.g. 4200uS) the first time I run glxgears.
> "glxinfo" reports "Direct rendering: no".
This is bad news. It could come either from the fact that the Xorg
driver shuts hardware interrupts off (there is nothing xenomai can do
about that), or it could be an SMI issue. What about using the driver
for the real graphic card you have ? Probably intel card? Do you observe
any big latencies if you stress the system with anything else than X?
> Power management options (ACPUI, APM): Disable ACPI (Advanced
> Configuration and Power Interface) Support --> Processor Disable CPU
> Frequency Scaling Disable CPU idle PM support Disable Power Managment
> Support
Disabling ACPI is a bad idea. As repeated many times, only
ACPI_PROCESSOR should be disabled, not ACPI.
>
> Real-time sub-system: Enable Machine--> SMI workaround Enable
> Machine--> globally disable SMI
Do you have a message in the kernel boot logs telling you that the SMI
workaround actually worked?
>
> I have read through this:
> http://svn.gna.org/svn/xenomai/trunk/TROUBLESHOOTING and tried to
> find anything relevant. I am booting from an on board compact flash
> via USB. I wondered if this could be the problem. Output of hdparm:
Well, this is not the latest version of the TROUBLESHOOTING guide. The
latest version is in Xenomai sources, or accessible through our website.
Though I am not sure much things have changed.
> IDE Controller settings "HDC configure as" Options: "IDE", "RAID",
> "AHCI"
Do not select IDE here, it probably uses SMIs
>
> USB Configuration "USB Legacy" Enable/Disable "EHCI1" Enable/Disable
> "EHCI2" " "UHCI1" " "UHCI2" ... "UHCI5"
> "Per-Port Control2" Enable/Disable "USB Pre-fetch Feature"
> Enable/Disable "USB Pre-fetch Time" 2ms/4ms "USB HC Alignment"
> Enable/Disable
Do not select USB legacy, it probably uses SMI.
>
> Chipset Configuration "CRID/SRID" Enable/Disable "Port 80h Cycles"
> LPC bus/PCI bus "DMI Link ASPM Control" Enable/Disable "Automatic
> ASMO" Auto/Manual "ASPM L0s Support" Enable/Disable "ASPM L0sL1
> Support" Enable/Disable "VT-d" Enable/Disable
>
> ACPI Table/Feature Control "FACP - C2 Latency Value" Enable/Disable
> "FACP - C3 Latency Value" Enable/Disable "FACP - RTC S4 Wakeup"
> Enable/Disable "APIC - IO APIC Mode" Enable/Disable "HPET - HPET
> Support" Enable/Disable
You probably want the APIC and IO APIC.
> So, could anyone suggest what I might try to improve the system?
> Sorry for the torrent of information... I thought it better to give
> as much info as I could think of than to not provide enough to make a
> diagnosis!
test whether you have issues without the X server,
if yes, check whether the SMI workaround actually works,
if no, test with another X server (the one specific to your graphic
card, presumably the intel one).
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-08-13 14:17 [Xenomai-help] Very high latencies under stress testing edward.robbins
2010-08-13 14:35 ` Gilles Chanteperdrix
@ 2010-08-13 14:40 ` Philippe Gerum
2010-08-13 16:15 ` Philippe Gerum
1 sibling, 1 reply; 38+ messages in thread
From: Philippe Gerum @ 2010-08-13 14:40 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
On Fri, 2010-08-13 at 15:17 +0100,
edward.robbins@domain.hid wrote:
> Hello all,
>
> I have just set up my first xenomai system, and though I believe I
> have followed most of the guidelines, if I run latency it sits at
> around 8uS max, until I run something to stress the system (e.g.
> startx, or killing the x server) when it jumps to 700-800uS.
>
> I wonder if this is to do with graphics? I have set "NoAccel" in the
> driver section of Xorg.conf (I am using fbdev). I also notice that
> latencies go massive (e.g. 4200uS) the first time I run glxgears.
> "glxinfo" reports "Direct rendering: no".
Yes, this is likely related to some kernel resource(s) involved in
graphics, at least, this is a usual suspect - the fact that it happens
only(?) upon X server state transitions does not point the finger at SMI
issues, which are the other sources of high latencies on x86.
Typically, we had some issues over time with MTRR handling, inducing
either massive jitter or even crashes on x86. Normally, the Adeos patch
would fix those issues as they are discovered, but it may well happen
that some bugs are still hiding.
Since your box does not bluntly crash, could you try running the I-pipe
tracer, to get a snapshot of the latest kernel activity before the max
latency is reached?
This howto explains how to set it up:
http://www.xenomai.org/index.php/I-pipe:Tracer
In case of doubt about the way to get those traces, just ask.
>
> This is a core 2 duo system (MEN F19P cPCI) with ICH9M-SFF chipset. I
> am running debian (lenny) and have followed the guide in the wiki
> (here: http://www.xenomai.org/index.php/Building_Debian_packages) to
> install kernel 2.6.32.15 and xenomai 2.5.4. I have made the following
> selections for kernel configuration in order to try and prevent
> latency issues:
>
> Processor type and features:
> Enable interrupt pipeline
> Enable high resolution timer support
> Disable dell laptop support
> Processor family --> Core 2/Newer Xeon
> Preemption model --> Preemptible kernel (low latency desktop)
>
> Bus options (PCI etc):
> Disable PCI express hotplug driver
> Disable message signalled interrupts (MSI and MSI-X)
> Disable PCCard (PCMCIA/Cardbus support)
> Disable support for PCI hotplug
>
> Device drivers:
> Disable Memory Technology Device (MTD) support
> Disable Fusion MPT device support
> Disable I20 device support
> Disable ISDN support
>
> Power management options (ACPUI, APM):
> Disable ACPI (Advanced Configuration and Power Interface)
> Support --> Processor
> Disable CPU Frequency Scaling
> Disable CPU idle PM support
> Disable Power Managment Support
>
> Real-time sub-system:
> Enable Machine--> SMI workaround
> Enable Machine--> globally disable SMI
>
> I have read through this:
> http://svn.gna.org/svn/xenomai/trunk/TROUBLESHOOTING and tried to find
> anything relevant. I am booting from an on board compact flash via
> USB. I wondered if this could be the problem. Output of hdparm:
>
> hdparm -v /dev/sda
>
> readonly = 0 (off)
> readahead = 256 (on)
> geometry = 1024/255/63, sectors = 31227840, start = 0
>
> hdparm -acdgkmur /dev/sda
>
> HDIO_GET_MULTICOUNT failed: Invalid argument
> HDIO_GET_32BIT failed: Invalid argument
> HDIO_GET_UNMASKINTR failed: Invalid argument
> HDIO_GET_DMA failed: Invaid argument
> HDIO_GET_KEEPSETTINGS failed: Invalid argument
> (reast of output same as hdparm -v)
>
> hdparm -t /dev/sda
>
> /dev/sda:
> Timing buffered disk reads: 100MB in 3.01 seconds = 33.24 MB/sec
>
> hdparm -T /dev/sda
>
> /dev/sda:
> Timing cached reads: 11006 MB in 2.00 seconds = 5503.00 MB/sec
>
> Then I did cat /proc/scsi/scsi:
> Host: scsi4 Channel: 00 Id: 00 Lun: 00
> Vendor: Generic Model: Flash HS-CF Rev: 1.68
> Type: Direct-Access ANSI SCSI
> revision: 00
>
> Also, this embedded system has a lot of configuration options in the
> BIOS (more than I have seen on any other system). Some seem like they
> could be very useful but are currently unusable (e.g. if I set "SMI
> handler" to off, the system will no longer boot from compact flash).
> There are also other options that might be relevant. I have tried
> playing with them, but am not even sure what some are and the manual
> is quite cryptic:
>
> IDE Controller settings
> "HDC configure as" Options: "IDE", "RAID", "AHCI"
>
> USB Configuration
> "USB Legacy" Enable/Disable
> "EHCI1" Enable/Disable
> "EHCI2" "
> "UHCI1" "
> "UHCI2"
> ...
> "UHCI5"
> "Per-Port Control2" Enable/Disable
> "USB Pre-fetch Feature" Enable/Disable
> "USB Pre-fetch Time" 2ms/4ms
> "USB HC Alignment" Enable/Disable
>
> Chipset Configuration
> "CRID/SRID" Enable/Disable
> "Port 80h Cycles" LPC bus/PCI bus
> "DMI Link ASPM Control" Enable/Disable
> "Automatic ASMO" Auto/Manual
> "ASPM L0s Support" Enable/Disable
> "ASPM L0sL1 Support" Enable/Disable
> "VT-d" Enable/Disable
>
> ACPI Table/Feature Control
> "FACP - C2 Latency Value" Enable/Disable
> "FACP - C3 Latency Value" Enable/Disable
> "FACP - RTC S4 Wakeup" Enable/Disable
> "APIC - IO APIC Mode" Enable/Disable
> "HPET - HPET Support" Enable/Disable
>
> PCI Express Root Port 1/2/3/4/5/6 Settings
> "ASPM" Enable/Disable
> "Automatic ASPM" Auto/Manual
> "ASPM L0s" Root&Endpoint Ports/ Disabled/ Root Port Only/
> Endpoint port Only
> "ASPM L1" Enable/Disable
> "URR" Enable/Disable
> "FER" Enable/Disable
> "NFER" Enable/Disable
> "CER" Enable/Disable
> "CTO" Enable/Disable
> "SEFE" Enable/Disable
> "SENFE" Enable/Disable
> "SECE" Enable/Disable
> "PME Interrupt" Enable/Disable
> "PME SCI" Enable/Disable
> "Hot Plug SCI" Enable/Disable
>
> Advanced CPU Control
> "P-States" Enable/Disable
> "CMP Support" Enable/Disable
> "Vanderpool Technology" Enable/Disable
> "SMRR Support" Auto/Disable
> "C-States" Enable/Disable
> "Enhanced C-States" Enable/Disable
> "C-State Pop Up Mode" Enable/Disable
> "C-State Pop Down Mode" Enable/Disable
> "C4 Exit Timing Mode" Fast/Slow/Default/Force Slow
> "DeepC4" Enable/Disable
> "Hard C4E" Enable/Disable
> "Enable C6" Enable/Disable
> "EMTTM" Enable/Disable
> "Bi-directional PROCHOT#" Enable/Disable
> "ACPI 3.0 T-States" Enable/Disable
> "DTS" Enable/Disable"
> ... (lots more options that I am not sure what they really
> are for!)
>
> Platfoirm Power Management
> "Storage Break Event" Enable/Disable
> "PCIE Break Event" Enable/Disable
> "PCI Break Event" Enable/Disable
> "EHCI Break Event" Enable/Disable
> "UHCI Break Event" Enable/Disable
> "HDA Break Event" Enable/Disable
> "ACPI S3" Enable/Disable
>
> So, could anyone suggest what I might try to improve the system? Sorry
> for the torrent of information... I thought it better to give as much
> info as I could think of than to not provide enough to make a
> diagnosis!
>
> Thanks,
>
> Edward Robbins
>
> Control Systems Engineer
> Oxford Technologies Ltd
> UKAEA Culham
> Joint European Torus, Remote Handling Division
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid
> https://mail.gna.org/listinfo/xenomai-help
--
Philippe.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-08-13 14:40 ` Philippe Gerum
@ 2010-08-13 16:15 ` Philippe Gerum
0 siblings, 0 replies; 38+ messages in thread
From: Philippe Gerum @ 2010-08-13 16:15 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
On Fri, 2010-08-13 at 16:40 +0200, Philippe Gerum wrote:
> On Fri, 2010-08-13 at 15:17 +0100,
> edward.robbins@domain.hid wrote:
> > Hello all,
> >
> > I have just set up my first xenomai system, and though I believe I
> > have followed most of the guidelines, if I run latency it sits at
> > around 8uS max, until I run something to stress the system (e.g.
> > startx, or killing the x server) when it jumps to 700-800uS.
> >
> > I wonder if this is to do with graphics? I have set "NoAccel" in the
> > driver section of Xorg.conf (I am using fbdev). I also notice that
> > latencies go massive (e.g. 4200uS) the first time I run glxgears.
> > "glxinfo" reports "Direct rendering: no".
>
> Yes, this is likely related to some kernel resource(s) involved in
> graphics, at least, this is a usual suspect - the fact that it happens
> only(?) upon X server state transitions does not point the finger at SMI
> issues, which are the other sources of high latencies on x86.
A good hint to detect SMI issues is to run the Xenomai latency test in
console mode, preferably without any X-server started, so we don't get
polluted by another potential source of issues. If that test runs with
no significant latency peak on your box during more than, say, two hours
(*), writing a file of a significant size several times on your CF
during this time (and syncing the related fs), then your box is probably
immune from those SMI issues.
(*) Some SMI events are timed and do occur periodically.
>
> Typically, we had some issues over time with MTRR handling, inducing
> either massive jitter or even crashes on x86. Normally, the Adeos patch
> would fix those issues as they are discovered, but it may well happen
> that some bugs are still hiding.
>
> Since your box does not bluntly crash, could you try running the I-pipe
> tracer, to get a snapshot of the latest kernel activity before the max
> latency is reached?
>
> This howto explains how to set it up:
> http://www.xenomai.org/index.php/I-pipe:Tracer
>
> In case of doubt about the way to get those traces, just ask.
>
> >
> > This is a core 2 duo system (MEN F19P cPCI) with ICH9M-SFF chipset. I
> > am running debian (lenny) and have followed the guide in the wiki
> > (here: http://www.xenomai.org/index.php/Building_Debian_packages) to
> > install kernel 2.6.32.15 and xenomai 2.5.4. I have made the following
> > selections for kernel configuration in order to try and prevent
> > latency issues:
> >
> > Processor type and features:
> > Enable interrupt pipeline
> > Enable high resolution timer support
> > Disable dell laptop support
> > Processor family --> Core 2/Newer Xeon
> > Preemption model --> Preemptible kernel (low latency desktop)
> >
> > Bus options (PCI etc):
> > Disable PCI express hotplug driver
> > Disable message signalled interrupts (MSI and MSI-X)
> > Disable PCCard (PCMCIA/Cardbus support)
> > Disable support for PCI hotplug
> >
> > Device drivers:
> > Disable Memory Technology Device (MTD) support
> > Disable Fusion MPT device support
> > Disable I20 device support
> > Disable ISDN support
> >
> > Power management options (ACPUI, APM):
> > Disable ACPI (Advanced Configuration and Power Interface)
> > Support --> Processor
> > Disable CPU Frequency Scaling
> > Disable CPU idle PM support
> > Disable Power Managment Support
> >
> > Real-time sub-system:
> > Enable Machine--> SMI workaround
> > Enable Machine--> globally disable SMI
> >
> > I have read through this:
> > http://svn.gna.org/svn/xenomai/trunk/TROUBLESHOOTING and tried to find
> > anything relevant. I am booting from an on board compact flash via
> > USB. I wondered if this could be the problem. Output of hdparm:
> >
> > hdparm -v /dev/sda
> >
> > readonly = 0 (off)
> > readahead = 256 (on)
> > geometry = 1024/255/63, sectors = 31227840, start = 0
> >
> > hdparm -acdgkmur /dev/sda
> >
> > HDIO_GET_MULTICOUNT failed: Invalid argument
> > HDIO_GET_32BIT failed: Invalid argument
> > HDIO_GET_UNMASKINTR failed: Invalid argument
> > HDIO_GET_DMA failed: Invaid argument
> > HDIO_GET_KEEPSETTINGS failed: Invalid argument
> > (reast of output same as hdparm -v)
> >
> > hdparm -t /dev/sda
> >
> > /dev/sda:
> > Timing buffered disk reads: 100MB in 3.01 seconds = 33.24 MB/sec
> >
> > hdparm -T /dev/sda
> >
> > /dev/sda:
> > Timing cached reads: 11006 MB in 2.00 seconds = 5503.00 MB/sec
> >
> > Then I did cat /proc/scsi/scsi:
> > Host: scsi4 Channel: 00 Id: 00 Lun: 00
> > Vendor: Generic Model: Flash HS-CF Rev: 1.68
> > Type: Direct-Access ANSI SCSI
> > revision: 00
> >
> > Also, this embedded system has a lot of configuration options in the
> > BIOS (more than I have seen on any other system). Some seem like they
> > could be very useful but are currently unusable (e.g. if I set "SMI
> > handler" to off, the system will no longer boot from compact flash).
> > There are also other options that might be relevant. I have tried
> > playing with them, but am not even sure what some are and the manual
> > is quite cryptic:
> >
> > IDE Controller settings
> > "HDC configure as" Options: "IDE", "RAID", "AHCI"
> >
> > USB Configuration
> > "USB Legacy" Enable/Disable
> > "EHCI1" Enable/Disable
> > "EHCI2" "
> > "UHCI1" "
> > "UHCI2"
> > ...
> > "UHCI5"
> > "Per-Port Control2" Enable/Disable
> > "USB Pre-fetch Feature" Enable/Disable
> > "USB Pre-fetch Time" 2ms/4ms
> > "USB HC Alignment" Enable/Disable
> >
> > Chipset Configuration
> > "CRID/SRID" Enable/Disable
> > "Port 80h Cycles" LPC bus/PCI bus
> > "DMI Link ASPM Control" Enable/Disable
> > "Automatic ASMO" Auto/Manual
> > "ASPM L0s Support" Enable/Disable
> > "ASPM L0sL1 Support" Enable/Disable
> > "VT-d" Enable/Disable
> >
> > ACPI Table/Feature Control
> > "FACP - C2 Latency Value" Enable/Disable
> > "FACP - C3 Latency Value" Enable/Disable
> > "FACP - RTC S4 Wakeup" Enable/Disable
> > "APIC - IO APIC Mode" Enable/Disable
> > "HPET - HPET Support" Enable/Disable
> >
> > PCI Express Root Port 1/2/3/4/5/6 Settings
> > "ASPM" Enable/Disable
> > "Automatic ASPM" Auto/Manual
> > "ASPM L0s" Root&Endpoint Ports/ Disabled/ Root Port Only/
> > Endpoint port Only
> > "ASPM L1" Enable/Disable
> > "URR" Enable/Disable
> > "FER" Enable/Disable
> > "NFER" Enable/Disable
> > "CER" Enable/Disable
> > "CTO" Enable/Disable
> > "SEFE" Enable/Disable
> > "SENFE" Enable/Disable
> > "SECE" Enable/Disable
> > "PME Interrupt" Enable/Disable
> > "PME SCI" Enable/Disable
> > "Hot Plug SCI" Enable/Disable
> >
> > Advanced CPU Control
> > "P-States" Enable/Disable
> > "CMP Support" Enable/Disable
> > "Vanderpool Technology" Enable/Disable
> > "SMRR Support" Auto/Disable
> > "C-States" Enable/Disable
> > "Enhanced C-States" Enable/Disable
> > "C-State Pop Up Mode" Enable/Disable
> > "C-State Pop Down Mode" Enable/Disable
> > "C4 Exit Timing Mode" Fast/Slow/Default/Force Slow
> > "DeepC4" Enable/Disable
> > "Hard C4E" Enable/Disable
> > "Enable C6" Enable/Disable
> > "EMTTM" Enable/Disable
> > "Bi-directional PROCHOT#" Enable/Disable
> > "ACPI 3.0 T-States" Enable/Disable
> > "DTS" Enable/Disable"
> > ... (lots more options that I am not sure what they really
> > are for!)
> >
> > Platfoirm Power Management
> > "Storage Break Event" Enable/Disable
> > "PCIE Break Event" Enable/Disable
> > "PCI Break Event" Enable/Disable
> > "EHCI Break Event" Enable/Disable
> > "UHCI Break Event" Enable/Disable
> > "HDA Break Event" Enable/Disable
> > "ACPI S3" Enable/Disable
> >
> > So, could anyone suggest what I might try to improve the system? Sorry
> > for the torrent of information... I thought it better to give as much
> > info as I could think of than to not provide enough to make a
> > diagnosis!
> >
> > Thanks,
> >
> > Edward Robbins
> >
> > Control Systems Engineer
> > Oxford Technologies Ltd
> > UKAEA Culham
> > Joint European Torus, Remote Handling Division
> > _______________________________________________
> > Xenomai-help mailing list
> > Xenomai-help@domain.hid
> > https://mail.gna.org/listinfo/xenomai-help
>
--
Philippe.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-08-13 14:35 ` Gilles Chanteperdrix
@ 2010-08-16 12:13 ` edward.robbins
2010-08-16 12:32 ` Gilles Chanteperdrix
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-08-16 12:13 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
On Friday, 13 August, 2010 3:35pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@domain.hid> said:
> edward.robbins@domain.hidk wrote:
>>
>> I wonder if this is to do with graphics? I have set "NoAccel" in the
>> driver section of Xorg.conf (I am using fbdev). I also notice that
>> latencies go massive (e.g. 4200uS) the first time I run glxgears.
>> "glxinfo" reports "Direct rendering: no".
>
> This is bad news. It could come either from the fact that the Xorg
> driver shuts hardware interrupts off (there is nothing xenomai can do
> about that), or it could be an SMI issue. What about using the driver
> for the real graphic card you have ? Probably intel card? Do you observe
> any big latencies if you stress the system with anything else than X?
>
>> Power management options (ACPUI, APM): Disable ACPI (Advanced
>> Configuration and Power Interface) Support --> Processor Disable CPU
>> Frequency Scaling Disable CPU idle PM support Disable Power Managment
>> Support
>
> Disabling ACPI is a bad idea. As repeated many times, only
> ACPI_PROCESSOR should be disabled, not ACPI.
>
Thanks for your helpful responses.
I'm not working on this project again until next week, but on Friday I was able to
o Recompile the kernel with ACPI enabled
o Boot with the 'SMI handler' BIOS option set to disabled....
according to the help text this option should be disabled if 'an RTOS
is installed' - I presume this means that SMIs are completely disabled
and therefore SMIs cannot be the source of the problem
(very convenient BIOS option... now I begin to appreciate the expense of this board!)
o Changed xorg to use the intel video driver
After doing this I still have problems with latencies and X, but did not have a chance to stress the system with non-graphics tasks. I am thinking that when I get back to it next week I will compile the kernel a few times and also try writing a large file a number of times to the disk as Philippe suggested. Hopefully this will not cause any problems and I can then more confidently attribute the high latency to the graphics system. I will also attempt to install the I-pipe tracer as suggested. I'll update when (if!?) I get that far.
Thanks
Edward
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-08-16 12:13 ` edward.robbins
@ 2010-08-16 12:32 ` Gilles Chanteperdrix
2010-09-03 16:30 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-08-16 12:32 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
>
> On Friday, 13 August, 2010 3:35pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
>
>> edward.robbins@domain.hid wrote:
>>> I wonder if this is to do with graphics? I have set "NoAccel" in the
>>> driver section of Xorg.conf (I am using fbdev). I also notice that
>>> latencies go massive (e.g. 4200uS) the first time I run glxgears.
>>> "glxinfo" reports "Direct rendering: no".
>> This is bad news. It could come either from the fact that the Xorg
>> driver shuts hardware interrupts off (there is nothing xenomai can do
>> about that), or it could be an SMI issue. What about using the driver
>> for the real graphic card you have ? Probably intel card? Do you observe
>> any big latencies if you stress the system with anything else than X?
>>
>>> Power management options (ACPUI, APM): Disable ACPI (Advanced
>>> Configuration and Power Interface) Support --> Processor Disable CPU
>>> Frequency Scaling Disable CPU idle PM support Disable Power Managment
>>> Support
>> Disabling ACPI is a bad idea. As repeated many times, only
>> ACPI_PROCESSOR should be disabled, not ACPI.
>>
>
> Thanks for your helpful responses.
>
> I'm not working on this project again until next week, but on Friday I was able to
>
> o Recompile the kernel with ACPI enabled
> o Boot with the 'SMI handler' BIOS option set to disabled....
> according to the help text this option should be disabled if 'an RTOS
> is installed' - I presume this means that SMIs are completely disabled
> and therefore SMIs cannot be the source of the problem
> (very convenient BIOS option... now I begin to appreciate the expense of this board!)
> o Changed xorg to use the intel video driver
Now you can try NoAccel with the intel video driver too....
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-08-16 12:32 ` Gilles Chanteperdrix
@ 2010-09-03 16:30 ` edward.robbins
2010-09-04 8:51 ` Philippe Gerum
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-09-03 16:30 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 4039 bytes --]
I have now installed the i-pipe tracer and run some tests. Yesterday I thought I had gotten a high latency without X running, while compiling the kernel to stress the system, but now I think I might have been mistaken. Either way I was using a kernel whose configuration I couldn't remember, and didn't have the I-Pipe tracer installed at that time, so the observation wasn't particularly useful.
Today I have tried using the intel video driver with the option "NoAccel", and that seems to stop the high latencies; with this option I can kill X, restart it, and run glxgears without issues, all while compiling the linux kernel and having xeno-test or latency running. The highest latency I have gotten so far is 18uS.
However, if anyone is interested I have made a trace without the NoAccel option, when the latency jumped to 1113uS upon starting X, attached.
A couple of other things:
Yesterday when running xeno-test, I got a few of these messages:
"INFO: task sync:20539 blocked for more than 120 seconds...."
I have not seen this again today, and I don't know if it could be related, but I was also getting lots of strange USB disconnect sort of messages yesterday... I haven't seen any more today, and as I said before that kernel may have been useless anyway.
I am also getting this message from xeno-test:
"FATAL: module xeno-nucleus not found"
And:
"Warning Linux is compiled to use FPU in kernel space
For this reason, switch test can not test using FPU in Linux Kernel-space"
I presume these last two are because I did something wrong at kernel compile time?
Also, I tried to compile Xenomai 2.5.4 with a 2.6.34 kernel because it has a network driver that I really need, but the build failed. I think this has been resolved previously (as I have seen some information in the mailing list about a problem in the debian kernel patch script), but am not sure how to use the corrected script with my system. Can anyone help?
I will keep testing.
Thanks,
Edward
On Monday, 16 August, 2010 1:32pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hid wrote:
>>
>> On Friday, 13 August, 2010 3:35pm, "Gilles Chanteperdrix"
>> <gilles.chanteperdrix@xenomai.org> said:
>>
>>> edward.robbins@domain.hid wrote:
>>>> I wonder if this is to do with graphics? I have set "NoAccel" in the
>>>> driver section of Xorg.conf (I am using fbdev). I also notice that
>>>> latencies go massive (e.g. 4200uS) the first time I run glxgears.
>>>> "glxinfo" reports "Direct rendering: no".
>>> This is bad news. It could come either from the fact that the Xorg
>>> driver shuts hardware interrupts off (there is nothing xenomai can do
>>> about that), or it could be an SMI issue. What about using the driver
>>> for the real graphic card you have ? Probably intel card? Do you observe
>>> any big latencies if you stress the system with anything else than X?
>>>
>>>> Power management options (ACPUI, APM): Disable ACPI (Advanced
>>>> Configuration and Power Interface) Support --> Processor Disable CPU
>>>> Frequency Scaling Disable CPU idle PM support Disable Power Managment
>>>> Support
>>> Disabling ACPI is a bad idea. As repeated many times, only
>>> ACPI_PROCESSOR should be disabled, not ACPI.
>>>
>>
>> Thanks for your helpful responses.
>>
>> I'm not working on this project again until next week, but on Friday I was able
>> to
>>
>> o Recompile the kernel with ACPI enabled
>> o Boot with the 'SMI handler' BIOS option set to disabled....
>> according to the help text this option should be disabled if 'an RTOS
>> is installed' - I presume this means that SMIs are completely disabled
>> and therefore SMIs cannot be the source of the problem
>> (very convenient BIOS option... now I begin to appreciate the expense of this
>> board!)
>> o Changed xorg to use the intel video driver
>
> Now you can try NoAccel with the intel video driver too....
>
>
> --
> Gilles.
>
[-- Attachment #2: ipipe_trace --]
[-- Type: application/octet-stream, Size: 11226 bytes --]
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 5423344453447 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
:| #*func -1215 0.378 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -1214 0.491 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*[14670] samplin 99 -1214 0.378 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -1214 0.221 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -1213 0.213 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -1213 0.319 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x80000001 -1213 0.281 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -1213 0.229 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -1212 0.573 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -1212 0.214 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -1212 0.210 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -1211 0.281 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -1211 0.214 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -1211 0.217 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -1211 0.187 __rt_task_wait_period+0xb (hisyscall_event+0x151)
: +*func -1210 0.195 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
: +*func -1210 0.198 xnpod_wait_thread_period+0xb (rt_task_wait_period+0x3b)
:| +*begin 0x80000000 -1210 0.270 xnpod_wait_thread_period+0x3d (rt_task_wait_period+0x3b)
:| #*func -1210 0.262 xnpod_suspend_thread+0x11 (xnpod_wait_thread_period+0x126)
:| #*func -1210 0.240 __xnpod_schedule+0x11 (xnpod_suspend_thread+0x281)
:| #*[14670] samplin 99 -1209 0.217 __xnpod_schedule+0x189 (xnpod_suspend_thread+0x281)
:| #*func -1209 0.367 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -1209 0.424 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*[13273] dd -1 -1208 0.420 __xnpod_schedule+0x834 (xnintr_clock_handler+0x130)
:| #func -1208 0.408 __ipipe_walk_pipeline+0x11 (__ipipe_dispatch_wired_nocheck+0x1da)
:| #end 0x000000f6 -1207 0.345 common_interrupt+0x39 (__ipipe_sync_stage+0x195)
: #func -1207 0.221 __ipipe_get_ioapic_irq_vector+0x4 (__ipipe_sync_stage+0x1ce)
: #func -1207 0.202 smp_call_function_single_interrupt+0x4 (__ipipe_sync_stage+0x21b)
: #func -1207 0.195 irq_enter+0x9 (smp_call_function_single_interrupt+0xe)
:| #begin 0x80000001 -1206 0.243 debug_smp_processor_id+0x44 (irq_enter+0x13)
:| #end 0x80000001 -1206 0.251 debug_smp_processor_id+0x94 (irq_enter+0x13)
: #func -1206 0.195 rcu_irq_enter+0x9 (irq_enter+0x1a)
:| #begin 0x80000001 -1206 0.240 debug_smp_processor_id+0x44 (rcu_irq_enter+0x1a)
:| #end 0x80000001 -1206 0.255 debug_smp_processor_id+0x94 (rcu_irq_enter+0x1a)
: #func -1205 0.202 idle_cpu+0x4 (irq_enter+0x21)
: #func -1205 0.206 add_preempt_count+0x9 (irq_enter+0x59)
: #func -1205 0.195 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -1205 0.262 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -1204 0.229 ipipe_check_context+0xda (add_preempt_count+0x1c)
: #func -1204 0.195 generic_smp_call_function_single_interrupt+0xd (smp_call_function_single_interrupt+0x13)
:| #begin 0x80000001 -1204 0.240 debug_smp_processor_id+0x44 (generic_smp_call_function_single_interrupt+0x1e)
:| #end 0x80000001 -1204 0.225 debug_smp_processor_id+0x94 (generic_smp_call_function_single_interrupt+0x1e)
:| #begin 0x80000001 -1204 0.232 debug_smp_processor_id+0x44 (generic_smp_call_function_single_interrupt+0x39)
:| #end 0x80000001 -1203 0.221 debug_smp_processor_id+0x94 (generic_smp_call_function_single_interrupt+0x39)
: #func -1203 0.199 _spin_lock+0x9 (generic_smp_call_function_single_interrupt+0x7d)
: #func -1203 0.191 add_preempt_count+0x9 (_spin_lock+0x1b)
: #func -1203 0.187 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -1203 0.251 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -1202 0.277 ipipe_check_context+0xda (add_preempt_count+0x1c)
: #func -1202 0.191 _spin_unlock+0x4 (generic_smp_call_function_single_interrupt+0xa7)
: #func -1202 0.195 sub_preempt_count+0x9 (_spin_unlock+0x15)
: #func -1202 0.187 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| #begin 0x80000001 -1201 0.251 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| #end 0x80000001 -1201 0.258 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: #func -1201 0.195 __cpa_flush_all+0x9 (generic_smp_call_function_single_interrupt+0xe6)
: #func -1201 0.191 ipipe_check_context+0x11 (__cpa_flush_all+0x26)
:| #begin 0x80000001 -1201 0.255 ipipe_check_context+0x33 (__cpa_flush_all+0x26)
:| #end 0x80000001 -1200 0.547 ipipe_check_context+0xda (__cpa_flush_all+0x26)
: #func -1200 0.195 __ipipe_restore_root+0xb (__cpa_flush_all+0x67)
:| #begin 0x80000001 -1200 0.240 __ipipe_restore_root+0x2d (__cpa_flush_all+0x67)
:| #end 0x80000001 -1199! 1173.258 __ipipe_restore_root+0x7d (__cpa_flush_all+0x67)
:| #begin 0x000000f6 -26+ 1.549 common_interrupt+0x20 (__cpa_flush_all+0x7f)
:| #func -24 0.472 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| #func -24 0.292 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| #func -24 0.390 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| #func -23 0.630 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| #func -23 0.318 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| #func -22 0.442 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| #*func -22 0.592 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| #*func -21 0.862 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| #*func -20 0.274 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| #*func -20+ 1.050 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| #*[14670] samplin 99 -19 0.686 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| #*func -18 0.292 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| #*event tick@79 -18 0.307 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| #*func -18 0.499 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| #*func -17 0.660 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| #*[13273] dd -1 -17 0.273 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| #*func -16+ 1.691 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -15+ 1.282 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*[14670] samplin 99 -13 0.896 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -13 0.247 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -12 0.311 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -12+ 1.710 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x80000001 -10 0.363 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -10 0.330 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -10+ 5.135 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -4 0.330 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -4 0.213 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -4 0.480 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -3 0.259 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -3 0.615 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -3 0.547 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: +*func -2 0.292 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: +*func -2 0.198 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: +*func -2 0.191 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| +*begin 0x80000001 -1+ 1.316 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| #*func 0 0.266 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| +*end 0x80000001 0 0.236 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< +*freeze 0x0010fc66 0 0.214 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| +*begin 0x80000001 0 0.251 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 0 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 0 0.648 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.210 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.187 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 1 0.262 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 1 0.199 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+*func 2 0.348 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+*func 2 0.281 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+*func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-09-03 16:30 ` edward.robbins
@ 2010-09-04 8:51 ` Philippe Gerum
2010-10-15 9:21 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Philippe Gerum @ 2010-09-04 8:51 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
On Fri, 2010-09-03 at 17:30 +0100,
edward.robbins@domain.hid wrote:
> I have now installed the i-pipe tracer and run some tests. Yesterday I thought I had gotten a high latency without X running, while compiling the kernel to stress the system, but now I think I might have been mistaken. Either way I was using a kernel whose configuration I couldn't remember, and didn't have the I-Pipe tracer installed at that time, so the observation wasn't particularly useful.
>
> Today I have tried using the intel video driver with the option "NoAccel", and that seems to stop the high latencies; with this option I can kill X, restart it, and run glxgears without issues, all while compiling the linux kernel and having xeno-test or latency running. The highest latency I have gotten so far is 18uS.
>
> However, if anyone is interested I have made a trace without the NoAccel option, when the latency jumped to 1113uS upon starting X, attached.
>
> A couple of other things:
>
> Yesterday when running xeno-test, I got a few of these messages:
> "INFO: task sync:20539 blocked for more than 120 seconds...."
> I have not seen this again today, and I don't know if it could be related, but I was also getting lots of strange USB disconnect sort of messages yesterday... I haven't seen any more today, and as I said before that kernel may have been useless anyway.
>
> I am also getting this message from xeno-test:
> "FATAL: module xeno-nucleus not found"
>
> And:
> "Warning Linux is compiled to use FPU in kernel space
> For this reason, switch test can not test using FPU in Linux Kernel-space"
>
> I presume these last two are because I did something wrong at kernel compile time?
>
> Also, I tried to compile Xenomai 2.5.4 with a 2.6.34 kernel because it has a network driver that I really need, but the build failed. I think this has been resolved previously (as I have seen some information in the mailing list about a problem in the debian kernel patch script), but am not sure how to use the corrected script with my system. Can anyone help?
>
> I will keep testing.
Please try this patch. Your trace log reveals that we are only virtually
masking interrupts while flushing the TLB, which is quite wrong.
diff --git a/arch/x86/include/asm/tlbflush.h b/arch/x86/include/asm/tlbflush.h
index 7f3eba0..b0a4112 100644
--- a/arch/x86/include/asm/tlbflush.h
+++ b/arch/x86/include/asm/tlbflush.h
@@ -30,7 +30,7 @@ static inline void __native_flush_tlb_global(void)
* from interrupts. (Use the raw variant because this code can
* be called from deep inside debugging code.)
*/
- raw_local_irq_save(flags);
+ local_irq_save_hw(flags);
cr4 = native_read_cr4();
/* clear PGE */
@@ -38,7 +38,7 @@ static inline void __native_flush_tlb_global(void)
/* write old PGE again and flush TLBs */
native_write_cr4(cr4);
- raw_local_irq_restore(flags);
+ local_irq_restore_hw(flags);
}
static inline void __native_flush_tlb_single(unsigned long addr)
--
Philippe.
^ permalink raw reply related [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-09-04 8:51 ` Philippe Gerum
@ 2010-10-15 9:21 ` edward.robbins
2010-10-15 11:54 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-15 9:21 UTC (permalink / raw)
To: Philippe Gerum; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 12164 bytes --]
On Saturday, 4 September, 2010 9:51am, "Philippe Gerum" <rpm@xenomai.org> said:
> On Fri, 2010-09-03 at 17:30 +0100,
> edward.robbins@domain.hidhnologies.co.uk wrote:
> > Today I have tried using the intel video driver with the option "NoAccel",
> and that seems to stop the high latencies; with this option I can kill X, restart
> it, and run glxgears without issues, all while compiling the linux kernel and
> having xeno-test or latency running. The highest latency I have gotten so far is
> 18uS.
> >
> > However, if anyone is interested I have made a trace without the NoAccel
> option, when the latency jumped to 1113uS upon starting X, attached.
> >
>
> Please try this patch. Your trace log reveals that we are only virtually
> masking interrupts while flushing the TLB, which is quite wrong.
>
Hi Phillipe,
I have tried the patch, and the only noticeable difference is that now when I have the NoAccel option set I am getting high latencies when I make actions such as killing the X server. Below is the ipipe trace. I presume this is going to be a problem even if I am not running X?
Thanks again,
Edward
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 4761785881144 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
:| # func -2144 0.326 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| # func -2143 0.390 __switch_to_xtra+0x8 (__switch_to+0x255)
:| # [ 3276] Xorg -1 -2143 0.427 __xnpod_schedule+0x834 (xnintr_clock_handler+0x130)
:| +func -2143 0.408 __ipipe_walk_pipeline+0x11 (__ipipe_dispatch_wired_nocheck+0x1da)
:| +end 0x000000f6 -2142 0.416 common_interrupt+0x39 (debug_smp_processor_id+0x97)
:| +begin 0x80000001 -2142 0.240 debug_smp_processor_id+0x44 (smp_call_function_single+0x122)
:| +end 0x80000001 -2141 0.262 debug_smp_processor_id+0x94 (smp_call_function_single+0x122)
: +func -2141 0.221 generic_exec_single+0x11 (smp_call_function_single+0x160)
: +func -2141 0.195 _spin_lock_irqsave+0x7 (generic_exec_single+0x3d)
: +func -2141 0.195 ipipe_check_context+0x11 (_spin_lock_irqsave+0x1b)
:| +begin 0x80000001 -2141 0.262 ipipe_check_context+0x33 (_spin_lock_irqsave+0x1b)
:| +end 0x80000001 -2140 0.244 ipipe_check_context+0xda (_spin_lock_irqsave+0x1b)
: #func -2140 0.206 add_preempt_count+0x9 (_spin_lock_irqsave+0x4c)
: #func -2140 0.202 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -2140 0.259 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -2139 0.251 ipipe_check_context+0xda (add_preempt_count+0x1c)
: #func -2139 0.195 _spin_unlock_irqrestore+0x4 (generic_exec_single+0x5d)
: #func -2139 0.191 __ipipe_restore_root+0xb (_spin_unlock_irqrestore+0x21)
:| #begin 0x80000001 -2139 0.236 __ipipe_restore_root+0x2d (_spin_unlock_irqrestore+0x21)
:| #end 0x80000001 -2139 0.236 __ipipe_restore_root+0x7d (_spin_unlock_irqrestore+0x21)
: #func -2138 0.191 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -2138 0.266 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -2138 0.213 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -2138 0.206 sub_preempt_count+0x9 (_spin_unlock_irqrestore+0x2b)
: +func -2137 0.206 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2137 0.259 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2137 0.255 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2137 0.221 native_send_call_func_single_ipi+0x4 (generic_exec_single+0x6b)
: +func -2136 0.199 flat_send_IPI_mask+0x11 (native_send_call_func_single_ipi+0x34)
:| +begin 0x80000001 -2136 0.247 flat_send_IPI_mask+0x36 (native_send_call_func_single_ipi+0x34)
:| +end 0x80000001 -2136 0.228 flat_send_IPI_mask+0x8e (native_send_call_func_single_ipi+0x34)
: +func -2136 0.206 sub_preempt_count+0x9 (smp_call_function_single+0x173)
: +func -2136 0.191 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2135 0.244 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2135 0.262 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2135 0.191 sub_preempt_count+0x9 (smp_call_function+0x47)
: +func -2135 0.187 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2135 0.244 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2134 0.232 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2134 0.187 ipipe_check_context+0x11 (set_mtrr+0x77)
:| +begin 0x80000001 -2134 0.251 ipipe_check_context+0x33 (set_mtrr+0x77)
:| +end 0x80000001 -2134! 10.477 ipipe_check_context+0xda (set_mtrr+0x77)
: #func -2123 0.206 generic_set_mtrr+0x11 (set_mtrr+0xdc)
: #func -2123 0.202 ipipe_check_context+0x11 (generic_set_mtrr+0x42)
:| #begin 0x80000001 -2123 0.262 ipipe_check_context+0x33 (generic_set_mtrr+0x42)
:| #end 0x80000001 -2122 0.259 ipipe_check_context+0xda (generic_set_mtrr+0x42)
:| #begin 0x80000001 -2122 0.221 generic_set_mtrr+0x85 (set_mtrr+0xdc)
:| #func -2122 0.199 prepare_set+0x4 (generic_set_mtrr+0x8a)
:| #func -2122 0.213 _spin_lock+0x9 (prepare_set+0x15)
:| #func -2122 0.191 add_preempt_count+0x9 (_spin_lock+0x1b)
:| #func -2121! 1840.932 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #func -280! 55.546 mtrr_wrmsr+0xd (prepare_set+0x79)
:| #func -225! 53.303 mtrr_wrmsr+0xd (generic_set_mtrr+0x111)
:| #func -172! 52.380 mtrr_wrmsr+0xd (generic_set_mtrr+0x129)
:| #func -119! 50.782 post_set+0x4 (generic_set_mtrr+0x12e)
:| #func -68! 40.665 mtrr_wrmsr+0xd (post_set+0x25)
:| #func -28+ 1.185 _spin_unlock+0x4 (post_set+0x4f)
:| #func -27 0.356 sub_preempt_count+0x9 (_spin_unlock+0x15)
:| #func -26 0.900 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| #end 0x80000001 -25+ 1.050 generic_set_mtrr+0x13f (set_mtrr+0xdc)
:| #begin 0x000000f6 -24 0.566 common_interrupt+0x20 (generic_set_mtrr+0x142)
:| #func -24 0.468 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| #func -23 0.266 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| #func -23 0.397 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| #func -23 0.465 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| #func -22 0.348 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| #func -22 0.450 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| #*func -21 0.634 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| #*func -21 0.892 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| #*func -20 0.352 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| #*func -19 0.585 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| #*[ 3272] -<?>- 99 -19 0.682 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| #*func -18 0.318 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| #*event tick@domain.hid -18 0.285 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| #*func -18 0.420 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| #*func -17 0.517 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| #*[ 3276] Xorg -1 -17 0.296 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| #*func -16+ 1.601 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -15+ 1.091 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*func -14 0.697 __switch_to_xtra+0x8 (__switch_to+0x255)
:| #*[ 3272] -<?>- 99 -13 0.945 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -12 0.495 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -11 0.307 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -11+ 1.526 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x80000001 -10 0.442 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -9 0.341 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -9+ 4.351 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -5 0.322 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -4 0.202 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -4 0.510 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -3 0.266 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -3 0.791 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -2 0.528 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: +*func -2 0.300 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: +*func -2 0.199 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: +*func -1 0.187 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| +*begin 0x80000001 -1+ 1.226 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| #*func 0 0.262 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| +*end 0x80000001 0 0.229 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< +*freeze 0x001f3e65 0 0.225 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| +*begin 0x80000001 0 0.251 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 0 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 0 0.708 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.199 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.183 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 1 0.262 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 2 0.199 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+*func 2 0.352 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+*func 2 0.281 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+*func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
[-- Attachment #2: Type: text/html, Size: 22243 bytes --]
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-15 9:21 ` edward.robbins
@ 2010-10-15 11:54 ` edward.robbins
2010-10-15 13:51 ` Gilles Chanteperdrix
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-15 11:54 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 12486 bytes --]
I am also finding that tasks are frequently hanging, causing ipipetraces with "INFO: task xxx:xxx blocked for more than 120 seconds". Ihave just had this with apt-get update, and was previously getting itwith grub-install. Could this be related?
Thanks again
On Friday, 15 October, 2010 10:21am, edward.robbins@domain.hid said:
On Saturday, 4 September, 2010 9:51am, "Philippe Gerum" <rpm@xenomai.org> said:
> On Fri, 2010-09-03 at 17:30 +0100,
> edward.robbins@domain.hid wrote:
> > Today I have tried using the intel video driver with the option "NoAccel",
> and that seems to stop the high latencies; with this option I can kill X, restart
> it, and run glxgears without issues, all while compiling the linux kernel and
> having xeno-test or latency running. The highest latency I have gotten so far is
> 18uS.
> >
> > However, if anyone is interested I have made a trace without the NoAccel
> option, when the latency jumped to 1113uS upon starting X, attached.
> >
>
> Please try this patch. Your trace log reveals that we are only virtually
> masking interrupts while flushing the TLB, which is quite wrong.
>
Hi Phillipe,
I have tried the patch, and the only noticeable difference is that now when I have the NoAccel option set I am getting high latencies when I make actions such as killing the X server. Below is the ipipe trace. I presume this is going to be a problem even if I am not running X?
Thanks again,
Edward
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 4761785881144 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
:| # func -2144 0.326 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| # func -2143 0.390 __switch_to_xtra+0x8 (__switch_to+0x255)
:| # [ 3276] Xorg -1 -2143 0.427 __xnpod_schedule+0x834 (xnintr_clock_handler+0x130)
:| +func -2143 0.408 __ipipe_walk_pipeline+0x11 (__ipipe_dispatch_wired_nocheck+0x1da)
:| +end 0x000000f6 -2142 0.416 common_interrupt+0x39 (debug_smp_processor_id+0x97)
:| +begin 0x80000001 -2142 0.240 debug_smp_processor_id+0x44 (smp_call_function_single+0x122)
:| +end 0x80000001 -2141 0.262 debug_smp_processor_id+0x94 (smp_call_function_single+0x122)
: +func -2141 0.221 generic_exec_single+0x11 (smp_call_function_single+0x160)
: +func -2141 0.195 _spin_lock_irqsave+0x7 (generic_exec_single+0x3d)
: +func -2141 0.195 ipipe_check_context+0x11 (_spin_lock_irqsave+0x1b)
:| +begin 0x80000001 -2141 0.262 ipipe_check_context+0x33 (_spin_lock_irqsave+0x1b)
:| +end 0x80000001 -2140 0.244 ipipe_check_context+0xda (_spin_lock_irqsave+0x1b)
: #func -2140 0.206 add_preempt_count+0x9 (_spin_lock_irqsave+0x4c)
: #func -2140 0.202 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -2140 0.259 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -2139 0.251 ipipe_check_context+0xda (add_preempt_count+0x1c)
: #func -2139 0.195 _spin_unlock_irqrestore+0x4 (generic_exec_single+0x5d)
: #func -2139 0.191 __ipipe_restore_root+0xb (_spin_unlock_irqrestore+0x21)
:| #begin 0x80000001 -2139 0.236 __ipipe_restore_root+0x2d (_spin_unlock_irqrestore+0x21)
:| #end 0x80000001 -2139 0.236 __ipipe_restore_root+0x7d (_spin_unlock_irqrestore+0x21)
: #func -2138 0.191 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -2138 0.266 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -2138 0.213 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -2138 0.206 sub_preempt_count+0x9 (_spin_unlock_irqrestore+0x2b)
: +func -2137 0.206 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2137 0.259 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2137 0.255 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2137 0.221 native_send_call_func_single_ipi+0x4 (generic_exec_single+0x6b)
: +func -2136 0.199 flat_send_IPI_mask+0x11 (native_send_call_func_single_ipi+0x34)
:| +begin 0x80000001 -2136 0.247 flat_send_IPI_mask+0x36 (native_send_call_func_single_ipi+0x34)
:| +end 0x80000001 -2136 0.228 flat_send_IPI_mask+0x8e (native_send_call_func_single_ipi+0x34)
: +func -2136 0.206 sub_preempt_count+0x9 (smp_call_function_single+0x173)
: +func -2136 0.191 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2135 0.244 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2135 0.262 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2135 0.191 sub_preempt_count+0x9 (smp_call_function+0x47)
: +func -2135 0.187 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2135 0.244 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2134 0.232 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2134 0.187 ipipe_check_context+0x11 (set_mtrr+0x77)
:| +begin 0x80000001 -2134 0.251 ipipe_check_context+0x33 (set_mtrr+0x77)
:| +end 0x80000001 -2134! 10.477 ipipe_check_context+0xda (set_mtrr+0x77)
: #func -2123 0.206 generic_set_mtrr+0x11 (set_mtrr+0xdc)
: #func -2123 0.202 ipipe_check_context+0x11 (generic_set_mtrr+0x42)
:| #begin 0x80000001 -2123 0.262 ipipe_check_context+0x33 (generic_set_mtrr+0x42)
:| #end 0x80000001 -2122 0.259 ipipe_check_context+0xda (generic_set_mtrr+0x42)
:| #begin 0x80000001 -2122 0.221 generic_set_mtrr+0x85 (set_mtrr+0xdc)
:| #func -2122 0.199 prepare_set+0x4 (generic_set_mtrr+0x8a)
:| #func -2122 0.213 _spin_lock+0x9 (prepare_set+0x15)
:| #func -2122 0.191 add_preempt_count+0x9 (_spin_lock+0x1b)
:| #func -2121! 1840.932 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #func -280! 55.546 mtrr_wrmsr+0xd (prepare_set+0x79)
:| #func -225! 53.303 mtrr_wrmsr+0xd (generic_set_mtrr+0x111)
:| #func -172! 52.380 mtrr_wrmsr+0xd (generic_set_mtrr+0x129)
:| #func -119! 50.782 post_set+0x4 (generic_set_mtrr+0x12e)
:| #func -68! 40.665 mtrr_wrmsr+0xd (post_set+0x25)
:| #func -28+ 1.185 _spin_unlock+0x4 (post_set+0x4f)
:| #func -27 0.356 sub_preempt_count+0x9 (_spin_unlock+0x15)
:| #func -26 0.900 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| #end 0x80000001 -25+ 1.050 generic_set_mtrr+0x13f (set_mtrr+0xdc)
:| #begin 0x000000f6 -24 0.566 common_interrupt+0x20 (generic_set_mtrr+0x142)
:| #func -24 0.468 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| #func -23 0.266 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| #func -23 0.397 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| #func -23 0.465 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| #func -22 0.348 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| #func -22 0.450 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| #*func -21 0.634 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| #*func -21 0.892 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| #*func -20 0.352 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| #*func -19 0.585 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| #*[ 3272] -<?>- 99 -19 0.682 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| #*func -18 0.318 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| #*event tick@domain.hid -18 0.285 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| #*func -18 0.420 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| #*func -17 0.517 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| #*[ 3276] Xorg -1 -17 0.296 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| #*func -16+ 1.601 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -15+ 1.091 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*func -14 0.697 __switch_to_xtra+0x8 (__switch_to+0x255)
:| #*[ 3272] -<?>- 99 -13 0.945 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -12 0.495 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -11 0.307 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -11+ 1.526 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x80000001 -10 0.442 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -9 0.341 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -9+ 4.351 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -5 0.322 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -4 0.202 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -4 0.510 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -3 0.266 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -3 0.791 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -2 0.528 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: +*func -2 0.300 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: +*func -2 0.199 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: +*func -1 0.187 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| +*begin 0x80000001 -1+ 1.226 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| #*func 0 0.262 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| +*end 0x80000001 0 0.229 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< +*freeze 0x001f3e65 0 0.225 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| +*begin 0x80000001 0 0.251 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 0 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 0 0.708 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.199 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.183 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 1 0.262 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 2 0.199 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+*func 2 0.352 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+*func 2 0.281 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+*func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
[-- Attachment #2: Type: text/html, Size: 22680 bytes --]
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-15 11:54 ` edward.robbins
@ 2010-10-15 13:51 ` Gilles Chanteperdrix
2010-10-15 14:13 ` edward.robbins
2010-10-19 13:52 ` edward.robbins
0 siblings, 2 replies; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-15 13:51 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> I am also finding that tasks are frequently hanging, causing
> ipipetraces with "INFO: task xxx:xxx blocked for more than 120
> seconds". Ihave just had this with apt-get update, and was previously
> getting itwith grub-install. Could this be related?
Yes. There is obviously an issue in your patched kernel, we need to find
this first before we draw any conclusion from any other behaviour.
>From the trace you sent, it looks like it happens in the MTRR code, but
it could also be an SMI, or some other bug. For debugging purposes,
could you try disabling MTRRs in the kernel configuration?
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-15 13:51 ` Gilles Chanteperdrix
@ 2010-10-15 14:13 ` edward.robbins
2010-10-15 14:25 ` Gilles Chanteperdrix
2010-10-15 14:33 ` Philippe Gerum
2010-10-19 13:52 ` edward.robbins
1 sibling, 2 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-15 14:13 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 875 bytes --]
Will do. Should I leave in Philippes patch? I will assume no for now...
On Friday, 15 October, 2010 2:51pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@domain.hid> said:
> edward.robbins@domain.hid wrote:
> > I am also finding that tasks are frequently hanging, causing
> > ipipetraces with "INFO: task xxx:xxx blocked for more than 120
> > seconds". Ihave just had this with apt-get update, and was previously
> > getting itwith grub-install. Could this be related?
>
> Yes. There is obviously an issue in your patched kernel, we need to find
> this first before we draw any conclusion from any other behaviour.
>
> From the trace you sent, it looks like it happens in the MTRR code, but
> it could also be an SMI, or some other bug. For debugging purposes,
> could you try disabling MTRRs in the kernel configuration?
>
> --
> Gilles.
>
[-- Attachment #2: Type: text/html, Size: 1017 bytes --]
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-15 14:13 ` edward.robbins
@ 2010-10-15 14:25 ` Gilles Chanteperdrix
2010-10-15 14:33 ` Philippe Gerum
1 sibling, 0 replies; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-15 14:25 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Will do. Should I leave in Philippes patch? I will assume no for now...
I would say you can keep it. If it is possible try both with and without.
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-15 14:13 ` edward.robbins
2010-10-15 14:25 ` Gilles Chanteperdrix
@ 2010-10-15 14:33 ` Philippe Gerum
1 sibling, 0 replies; 38+ messages in thread
From: Philippe Gerum @ 2010-10-15 14:33 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
On Fri, 2010-10-15 at 15:13 +0100,
edward.robbins@domain.hid wrote:
> Will do. Should I leave in Philippes patch? I will assume no for
> now...
>
That patch is correct and unrelated to the next problem. An other issue
is that the generic mtrr code is not ipipe aware, so it is not really
interrupt free.
> On Friday, 15 October, 2010 2:51pm, "Gilles Chanteperdrix"
> <gilles.chanteperdrix@xenomai.org> said:
>
> > edward.robbins@domain.hid wrote:
> > > I am also finding that tasks are frequently hanging, causing
> > > ipipetraces with "INFO: task xxx:xxx blocked for more than 120
> > > seconds". Ihave just had this with apt-get update, and was
> previously
> > > getting itwith grub-install. Could this be related?
> >
> > Yes. There is obviously an issue in your patched kernel, we need to
> find
> > this first before we draw any conclusion from any other behaviour.
> >
> > From the trace you sent, it looks like it happens in the MTRR code,
> but
> > it could also be an SMI, or some other bug. For debugging purposes,
> > could you try disabling MTRRs in the kernel configuration?
> >
> > --
> > Gilles.
> >
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid
> https://mail.gna.org/listinfo/xenomai-help
--
Philippe.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-15 13:51 ` Gilles Chanteperdrix
2010-10-15 14:13 ` edward.robbins
@ 2010-10-19 13:52 ` edward.robbins
2010-10-19 20:01 ` Gilles Chanteperdrix
1 sibling, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-19 13:52 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
Having disabled MTRR (and leaving in Phillipes patch) I am not getting unreasonable latencies unless I enable graphics acceleration. Can I be sure this has solved the issue?
Edward
On Friday, 15 October, 2010 2:51pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hid wrote:
>> I am also finding that tasks are frequently hanging, causing
>> ipipetraces with "INFO: task xxx:xxx blocked for more than 120
>> seconds". Ihave just had this with apt-get update, and was previously
>> getting itwith grub-install. Could this be related?
>
> Yes. There is obviously an issue in your patched kernel, we need to find
> this first before we draw any conclusion from any other behaviour.
>
> From the trace you sent, it looks like it happens in the MTRR code, but
> it could also be an SMI, or some other bug. For debugging purposes,
> could you try disabling MTRRs in the kernel configuration?
>
> --
> Gilles.
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-19 13:52 ` edward.robbins
@ 2010-10-19 20:01 ` Gilles Chanteperdrix
2010-10-23 11:08 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-19 20:01 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Having disabled MTRR (and leaving in Phillipes patch) I am not
> getting unreasonable latencies unless I enable graphics acceleration.
> Can I be sure this has solved the issue?
Yes, run a long stress test while running latency. The stress test
should stress anything (drivers, kernel services) you plan to use in the
final system.
The way we do this when validating Xenomai is by running the "dohell"
scripts, which relies on LTP to stress many kernel services.
http://git.xenomai.org/?p=mkrootfs.git;a=blob;f=tests/dohell;h=327a9f20755e23547f960e4c316141652f839bbf;hb=master
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-19 20:01 ` Gilles Chanteperdrix
@ 2010-10-23 11:08 ` edward.robbins
2010-10-23 11:13 ` Gilles Chanteperdrix
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-23 11:08 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 1294 bytes --]
Thanks, this script sounds like exactly what I need. I downloaded the latest snapshot of mkrootfs from git, but I don't want to install that on my rootfs. I'd just download the script alone, but looking at it I see it would want to run a script in /ltp as well, so I guess I need ltp too. Can you tell me an easier way to set up dohell that might save me sifting through the whole of ltp and mkrootfs to figure it out?
Thanks again,
Edward
On Tuesday, 19 October, 2010 9:01pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@domain.hid> said:
> edward.robbins@domain.hid.uk wrote:
> > Having disabled MTRR (and leaving in Phillipes patch) I am not
> > getting unreasonable latencies unless I enable graphics acceleration.
> > Can I be sure this has solved the issue?
>
> Yes, run a long stress test while running latency. The stress test
> should stress anything (drivers, kernel services) you plan to use in the
> final system.
>
> The way we do this when validating Xenomai is by running the "dohell"
> scripts, which relies on LTP to stress many kernel services.
> http://git.xenomai.org/?p=mkrootfs.git;a=blob;f=tests/dohell;h=327a9f20755e23547f960e4c316141652f839bbf;hb=master
>
> --
> Gilles.
>
[-- Attachment #2: Type: text/html, Size: 1438 bytes --]
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 11:08 ` edward.robbins
@ 2010-10-23 11:13 ` Gilles Chanteperdrix
2010-10-23 11:22 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 11:13 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Thanks, this script sounds like exactly what I need. I downloaded the
> latest snapshot of mkrootfs from git, but I don't want to install that
> on my rootfs. I'd just download the script alone, but looking at it I
> see it would want to run a script in /ltp as well, so I guess I need ltp
> too. Can you tell me an easier way to set up dohell that might save me
> sifting through the whole of ltp and mkrootfs to figure it out?
Well, you need to compile LTP. Building LTP (at least the version we use
to validate Xenomai) is a bit peculiar in cross-compiled environment,
but should be straight-forward if you are not cross-compiling. You
should find some documentation here:
http://ltp.sourceforge.net/documentation/how-to/ltp.php
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 11:13 ` Gilles Chanteperdrix
@ 2010-10-23 11:22 ` edward.robbins
2010-10-23 11:36 ` Gilles Chanteperdrix
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-23 11:22 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
Yep, sorry the words got to the keyboard bypassing my brain... it's built already...
On Saturday, 23 October, 2010 12:13pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hidnologies.co.uk wrote:
>> Thanks, this script sounds like exactly what I need. I downloaded the
>> latest snapshot of mkrootfs from git, but I don't want to install that
>> on my rootfs. I'd just download the script alone, but looking at it I
>> see it would want to run a script in /ltp as well, so I guess I need ltp
>> too. Can you tell me an easier way to set up dohell that might save me
>> sifting through the whole of ltp and mkrootfs to figure it out?
>
> Well, you need to compile LTP. Building LTP (at least the version we use
> to validate Xenomai) is a bit peculiar in cross-compiled environment,
> but should be straight-forward if you are not cross-compiling. You
> should find some documentation here:
> http://ltp.sourceforge.net/documentation/how-to/ltp.php
>
>
> --
> Gilles.
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 11:22 ` edward.robbins
@ 2010-10-23 11:36 ` Gilles Chanteperdrix
2010-10-23 13:45 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 11:36 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Yep, sorry the words got to the keyboard bypassing my brain... it's built already...
So, you are all set-up I guess. In one terminal, launch latency, in
another terminal, launch dohell. When, in that second terminal, you see:
Listening on any address 5566
>From another computer, run:
netcat the-box-where-dohell-runs 5566 > /dev/null
We can probably do something simpler with the inetd "discard" service,
but I have not tried yet.
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 11:36 ` Gilles Chanteperdrix
@ 2010-10-23 13:45 ` edward.robbins
2010-10-23 13:51 ` Gilles Chanteperdrix
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-23 13:45 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 888 bytes --]
Argh.. okay. Something is still wrong..very wrong..and went wrong fairly early in the test I think. Latencies went up to around 4500. I've attached a trace. Any clues?
Edward
On Saturday, 23 October, 2010 12:36pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hid wrote:
>> Yep, sorry the words got to the keyboard bypassing my brain... it's built
>> already...
>
> So, you are all set-up I guess. In one terminal, launch latency, in
> another terminal, launch dohell. When, in that second terminal, you see:
>
> Listening on any address 5566
>
> From another computer, run:
> netcat the-box-where-dohell-runs 5566 > /dev/null
>
> We can probably do something simpler with the inetd "discard" service,
> but I have not tried yet.
>
> --
> Gilles.
>
[-- Attachment #2: ipipe_trace.txt --]
[-- Type: text/plain, Size: 11083 bytes --]
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 35710222406884 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
:| #begin 0x80000000 -4505 0.251 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4504 0.210 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -4504 0.225 file_free_rcu+0x9 (__rcu_process_callbacks+0x1ee)
: +func -4504 0.202 kmem_cache_free+0x11 (file_free_rcu+0x33)
: +func -4504 0.195 ipipe_check_context+0x11 (kmem_cache_free+0x29)
:| +begin 0x80000001 -4503 0.251 ipipe_check_context+0x33 (kmem_cache_free+0x29)
:| +end 0x80000001 -4503 0.236 ipipe_check_context+0xda (kmem_cache_free+0x29)
:| #begin 0x80000001 -4503 0.236 debug_smp_processor_id+0x44 (kmem_cache_free+0x57)
:| #end 0x80000001 -4503 0.217 debug_smp_processor_id+0x94 (kmem_cache_free+0x57)
: #func -4502 0.206 __ipipe_restore_root+0xb (kmem_cache_free+0x231)
:| #begin 0x80000001 -4502 0.225 __ipipe_restore_root+0x2d (kmem_cache_free+0x231)
:| #end 0x80000001 -4502 0.202 __ipipe_restore_root+0x7d (kmem_cache_free+0x231)
: #func -4502 0.199 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -4502 0.255 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4501 0.217 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -4501 0.198 ipipe_check_context+0x11 (__rcu_process_callbacks+0x20e)
:| +begin 0x80000001 -4501 0.240 ipipe_check_context+0x33 (__rcu_process_callbacks+0x20e)
:| +end 0x80000001 -4501 0.274 ipipe_check_context+0xda (__rcu_process_callbacks+0x20e)
: #func -4500 0.198 __ipipe_restore_root+0xb (__rcu_process_callbacks+0x309)
:| #begin 0x80000001 -4500 0.221 __ipipe_restore_root+0x2d (__rcu_process_callbacks+0x309)
:| #end 0x80000001 -4500 0.228 __ipipe_restore_root+0x7d (__rcu_process_callbacks+0x309)
: #func -4500 0.187 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -4500 0.236 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4499 0.221 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -4499 0.191 raise_softirq+0x7 (__rcu_process_callbacks+0x31a)
: +func -4499 0.198 ipipe_check_context+0x11 (raise_softirq+0x1a)
:| +begin 0x80000001 -4499 0.251 ipipe_check_context+0x33 (raise_softirq+0x1a)
:| +end 0x80000001 -4499 0.243 ipipe_check_context+0xda (raise_softirq+0x1a)
: #func -4498 0.195 __ipipe_restore_root+0xb (raise_softirq+0x86)
:| #begin 0x80000001 -4498 0.236 __ipipe_restore_root+0x2d (raise_softirq+0x86)
:| #end 0x80000001 -4498 0.202 __ipipe_restore_root+0x7d (raise_softirq+0x86)
: #func -4498 0.187 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -4497 0.236 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4497 0.217 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
:| +begin 0x80000001 -4497 0.225 debug_smp_processor_id+0x44 (rcu_process_callbacks+0x42)
:| +end 0x80000001 -4497 0.217 debug_smp_processor_id+0x94 (rcu_process_callbacks+0x42)
: +func -4497 0.206 __rcu_process_callbacks+0x11 (rcu_process_callbacks+0x5b)
: +func -4496 0.198 force_quiescent_state+0x11 (__rcu_process_callbacks+0x6c)
: +func -4496 0.191 rcu_process_gp_end+0xd (__rcu_process_callbacks+0x78)
: +func -4496 0.187 ipipe_check_context+0x11 (rcu_process_gp_end+0x21)
:| +begin 0x80000001 -4496 0.247 ipipe_check_context+0x33 (rcu_process_gp_end+0x21)
:| +end 0x80000001 -4496 0.243 ipipe_check_context+0xda (rcu_process_gp_end+0x21)
: #func -4495 0.187 __ipipe_restore_root+0xb (rcu_process_gp_end+0x79)
:| #begin 0x80000001 -4495 0.236 __ipipe_restore_root+0x2d (rcu_process_gp_end+0x79)
:| #end 0x80000001 -4495 0.210 __ipipe_restore_root+0x7d (rcu_process_gp_end+0x79)
: #func -4495 0.187 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -4494 0.240 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4494 0.221 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -4494 0.195 check_for_new_grace_period+0xb (__rcu_process_callbacks+0x84)
: +func -4494! 4474.777 ipipe_check_context+0x11 (check_for_new_grace_period+0x22)
:| +begin 0x000000f6 -19 0.228 common_interrupt+0x20 (__ipipe_trace+0x729)
:| +func -19 0.251 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| +func -19 0.202 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| +func -18 0.195 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| +func -18 0.228 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| +func -18 0.221 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| +func -18 0.270 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| # func -17 0.240 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| # func -17 0.243 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| # func -17 0.202 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| # func -17 0.221 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| # [31843] -<?>- 99 -17 0.461 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| # func -16 0.206 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| # event tick@25 -16 0.210 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| # func -16 0.251 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| # func -15 0.274 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| # [17400] -<?>- -1 -15 0.221 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| # func -15 0.409 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| # func -14 0.536 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| # [31843] -<?>- 99 -14 0.375 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| # func -14 0.247 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| # func -13 0.214 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| + end 0x80000000 -13 0.521 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| + begin 0x00000039 -13 0.244 common_interrupt+0x20 (__ipipe_restore_pipeline_head+0x139)
:| + func -12 0.656 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| + func -12 0.337 __ipipe_set_irq_pending+0xd (__ipipe_handle_irq+0x173)
:| + func -11 0.304 irq_to_desc+0x4 (__ipipe_handle_irq+0x18b)
:| + func -11 0.401 __ipipe_ack_fasteoi_irq+0x4 (__ipipe_handle_irq+0x194)
:| + func -11 0.292 ack_apic_level+0xd (__ipipe_ack_fasteoi_irq+0x10)
:| + func -10 0.394 native_apic_mem_read+0x4 (ack_apic_level+0x4d)
:| + func -10+ 2.134 io_apic_modify_irq+0xb (ack_apic_level+0xb6)
:| + func -8+ 1.432 io_apic_sync+0x4 (io_apic_modify_irq+0x9e)
:| + func -6 0.296 native_apic_mem_write+0x4 (ack_apic_level+0xd0)
:| + end 0x00000039 -6 0.468 common_interrupt+0x39 (__ipipe_restore_pipeline_head+0x139)
:| + begin 0x80000001 -6 0.262 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| + end 0x80000001 -5 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| + begin 0x80000001 -5+ 1.488 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: + func -4 0.210 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: + func -3 0.195 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| + begin 0x80000001 -3 0.262 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| + end 0x80000001 -3 0.199 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: + func -3 0.570 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: + func -2 0.371 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: + func -2 0.337 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: + func -2 0.202 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: + func -1 0.199 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| + begin 0x80000001 -1+ 1.110 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| # func 0 0.273 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| + end 0x80000001 0 0.244 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< + freeze 0x00442d3e 0 0.266 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| + begin 0x80000001 0 0.270 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| + end 0x80000001 0 0.229 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| + begin 0x80000001 0 0.386 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+ func 1 0.214 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+ func 1 0.198 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| + begin 0x80000001 1 0.277 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| + end 0x80000001 1 0.225 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+ func 2 0.225 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+ func 2 0.187 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+ func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 13:45 ` edward.robbins
@ 2010-10-23 13:51 ` Gilles Chanteperdrix
2010-10-23 13:56 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 13:51 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Argh.. okay. Something is still wrong..very wrong..and went wrong
> fairly early in the test I think. Latencies went up to around 4500.
> I've attached a trace. Any clues?
What is your status with SMIs ?
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 13:51 ` Gilles Chanteperdrix
@ 2010-10-23 13:56 ` edward.robbins
2010-10-23 13:58 ` Gilles Chanteperdrix
2010-10-23 14:10 ` Gilles Chanteperdrix
0 siblings, 2 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-23 13:56 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
Oh no...
dmesg | grep SMI
CPU0: Thermal monitoring handled by SMI
CPU1: Thermal monitoring handled by SMI
So I guess that didn't work? I have used the 'Globally disable SMIs option' at kernel config time.... there is an option in the BIOS to disable SMI but I was having problems with it... will investigate. Any other options?
On Saturday, 23 October, 2010 2:51pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hid wrote:
>> Argh.. okay. Something is still wrong..very wrong..and went wrong
>> fairly early in the test I think. Latencies went up to around 4500.
>> I've attached a trace. Any clues?
>
> What is your status with SMIs ?
>
> --
> Gilles.
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 13:56 ` edward.robbins
@ 2010-10-23 13:58 ` Gilles Chanteperdrix
2010-10-23 14:32 ` edward.robbins
2010-10-23 14:10 ` Gilles Chanteperdrix
1 sibling, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 13:58 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Oh no...
>
> dmesg | grep SMI
>
> CPU0: Thermal monitoring handled by SMI
> CPU1: Thermal monitoring handled by SMI
>
> So I guess that didn't work? I have used the 'Globally disable SMIs option' at kernel config time.... there is an option in the BIOS to disable SMI but I was having problems with it... will investigate. Any other options?
What do the boot logs say?
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 13:56 ` edward.robbins
2010-10-23 13:58 ` Gilles Chanteperdrix
@ 2010-10-23 14:10 ` Gilles Chanteperdrix
1 sibling, 0 replies; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 14:10 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Oh no...
>
> dmesg | grep SMI
>
> CPU0: Thermal monitoring handled by SMI CPU1: Thermal monitoring
> handled by SMI
>
> So I guess that didn't work? I have used the 'Globally disable SMIs
> option' at kernel config time.... there is an option in the BIOS to
> disable SMI but I was having problems with it... will investigate.
> Any other options?
See:
http://www.xenomai.org/index.php/Configuring_x86_kernels#In_case_of_high_latencies
Note that if SMIs are involved in regulating temperature on your system,
disabling them may cause your CPU to overheat. So, when running dohell,
you should check the CPU temperature.
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 13:58 ` Gilles Chanteperdrix
@ 2010-10-23 14:32 ` edward.robbins
2010-10-23 14:37 ` Gilles Chanteperdrix
2010-10-23 15:16 ` edward.robbins
0 siblings, 2 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-23 14:32 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
Assuming you mean /var/log/messages and dmesg, they say nothing about SMIs except what I previously wrote.
I have managed to boot with SMI disabled in BIOS. The only trouble is I have to manually go into the BIOS bootloader and select to boot from USB every time or it reports there is no bootable device. It warns in the BIOS that disabling SMI will cause legacy USB boot to not work, so I presume this is the cause since my root fs is on a USB attached compact flash.
I will try now running tests with SMI disabled in the BIOS.
On Saturday, 23 October, 2010 2:58pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hidxfordtechnologies.co.uk wrote:
>> Oh no...
>>
>> dmesg | grep SMI
>>
>> CPU0: Thermal monitoring handled by SMI
>> CPU1: Thermal monitoring handled by SMI
>>
>> So I guess that didn't work? I have used the 'Globally disable SMIs option' at
>> kernel config time.... there is an option in the BIOS to disable SMI but I was
>> having problems with it... will investigate. Any other options?
>
> What do the boot logs say?
>
> --
> Gilles.
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 14:32 ` edward.robbins
@ 2010-10-23 14:37 ` Gilles Chanteperdrix
2010-10-23 14:48 ` edward.robbins
2010-10-23 15:16 ` edward.robbins
1 sibling, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 14:37 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Assuming you mean /var/log/messages and dmesg, they say nothing about
> SMIs except what I previously wrote.
Then it means, as I tried to explain in the link I posted, that Xenomai
SMI workaround code does not support your chipset. But adding it should
be really easy.
And yes, legacy usb is based on SMIs. But as far as I know, it is
something for keyboards and mice (emulating PS/2 peripherals using USB
peripherals). It should not prevent you from booting from an USB key.
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 14:37 ` Gilles Chanteperdrix
@ 2010-10-23 14:48 ` edward.robbins
0 siblings, 0 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-23 14:48 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
Yeah, sorry, was just dealing with one message at a time... see the next one.
Well, maybe it is something strange with my BIOS... it does explicitly say I wont be able to do "legacy usb boot". But then it works anyway if I go into the bios 'boot manager'. I will try playing with the boot order settings.
On Saturday, 23 October, 2010 3:37pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hidchnologies.co.uk wrote:
>> Assuming you mean /var/log/messages and dmesg, they say nothing about
>> SMIs except what I previously wrote.
>
> Then it means, as I tried to explain in the link I posted, that Xenomai
> SMI workaround code does not support your chipset. But adding it should
> be really easy.
>
> And yes, legacy usb is based on SMIs. But as far as I know, it is
> something for keyboards and mice (emulating PS/2 peripherals using USB
> peripherals). It should not prevent you from booting from an USB key.
>
> --
> Gilles.
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
@ 2010-10-23 14:54 edward.robbins
2010-10-23 15:37 ` Gilles Chanteperdrix
2010-10-23 16:13 ` Gilles Chanteperdrix
0 siblings, 2 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-23 14:54 UTC (permalink / raw)
To: xenomai
Forgot to copy the list:
Okay, so smi.c does not appear to contain my the PCI ID of my LPC chip. Motherboard has intel GS45 chipset, and "lspci -nn" says:
00:1f.0 ISA bridge [0601]: Intel Corporation ICH9M-E LPC Interface Controller [8086:2917] (rev 03)
Is this what I'm looking for? (What has ISA got to do with this?)
This PCI ID is not defined in either include/linux/pci_ids.h or include/asm-generic/xenomai/pci_ids.h, although there are these entries:
PCI_DEVICE_ID_INTEL_ICH9_7 0x2916
PCI_DEVICE_ID_INTEL_ICH9_8 0x2918
So I guess I should add
#define PCI_DEVICE_ID_INTEL_ICH9_9 0x2917
to xenomai/pci_ids.h, then add this define to smi.c, and see if magic happens?
Thanks for walking me through this!
Edward
On Saturday, 23 October, 2010 3:10pm, "Gilles Chanteperdrix" <gilles.chanteperdrix@xenomai.org> said:
> edward.robbins@domain.hid wrote:
>> Oh no...
>>
>> dmesg | grep SMI
>>
>> CPU0: Thermal monitoring handled by SMI CPU1: Thermal monitoring
>> handled by SMI
>>
>> So I guess that didn't work? I have used the 'Globally disable SMIs
>> option' at kernel config time.... there is an option in the BIOS to
>> disable SMI but I was having problems with it... will investigate.
>> Any other options?
>
> See:
> http://www.xenomai.org/index.php/Configuring_x86_kernels#In_case_of_high_latencies
>
> Note that if SMIs are involved in regulating temperature on your system,
> disabling them may cause your CPU to overheat. So, when running dohell,
> you should check the CPU temperature.
>
> --
> Gilles.
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 14:32 ` edward.robbins
2010-10-23 14:37 ` Gilles Chanteperdrix
@ 2010-10-23 15:16 ` edward.robbins
1 sibling, 0 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-23 15:16 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
[-- Attachment #1: Type: text/plain, Size: 1601 bytes --]
Well, tests with SMI handler disabled in BIOS did not work. Trace attached in case it's of interest. Compiling new kernel now...
On Saturday, 23 October, 2010 3:32pm, edward.robbins@domain.hid said:
> Assuming you mean /var/log/messages and dmesg, they say nothing about SMIs except
> what I previously wrote.
>
> I have managed to boot with SMI disabled in BIOS. The only trouble is I have to
> manually go into the BIOS bootloader and select to boot from USB every time or it
> reports there is no bootable device. It warns in the BIOS that disabling SMI will
> cause legacy USB boot to not work, so I presume this is the cause since my root fs
> is on a USB attached compact flash.
>
> I will try now running tests with SMI disabled in the BIOS.
>
>
> On Saturday, 23 October, 2010 2:58pm, "Gilles Chanteperdrix"
> <gilles.chanteperdrix@xenomai.orgi.org> said:
>
>> edward.robbins@domain.hid wrote:
>>> Oh no...
>>>
>>> dmesg | grep SMI
>>>
>>> CPU0: Thermal monitoring handled by SMI
>>> CPU1: Thermal monitoring handled by SMI
>>>
>>> So I guess that didn't work? I have used the 'Globally disable SMIs option' at
>>> kernel config time.... there is an option in the BIOS to disable SMI but I was
>>> having problems with it... will investigate. Any other options?
>>
>> What do the boot logs say?
>>
>> --
>> Gilles.
>>
>
>
>
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid> https://mail.gna.org/listinfo/xenomai-help
>
[-- Attachment #2: ipipe_trace.txt --]
[-- Type: text/plain, Size: 11767 bytes --]
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 766453929411 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
: +func -314138717 0.195 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138717 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138717 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138717 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138717 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138716 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138716 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138716 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138716 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138716 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138715 0.195 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138715 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138715 0.195 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138715 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138715 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138714 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138714 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138714 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138714 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138714 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138713 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138713 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138713 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138713 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138713 0.214 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138712 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138712 0.210 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138712 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138712 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138712 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138711 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138711 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138711 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138711 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138711 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138710 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138710 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138710 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138710 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138710 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138709 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138709 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138709 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138709 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138709 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138708 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138708 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138708 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138708 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138708 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138707 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138707 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138707 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138707 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138707 0.195 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138706 0.251 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138706 0.217 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138706 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138706 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138706 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138705 0.210 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138705 0.210 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138705 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138705 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138705 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138704 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138704 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138704 0.217 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138704 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138703 0.206 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138703 0.199 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138703 0.198 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
: +func -314138703 0.202 find_symbol_in_section+0x11 (each_symbol_in_section+0x3a)
-<invalid>-
:| # func -8 0.206 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| # event tick@23 -8 0.202 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| # func -8 0.251 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| # func -8 0.266 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| # [25391] -<?>- -1 -7 0.225 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| # func -7 0.420 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| # func -7 0.487 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| # [ 3299] -<?>- 99 -6 0.356 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| # func -6 0.251 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| # func -6 0.214 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| + end 0x80000000 -5 0.926 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| + end 0x80000001 -5 0.229 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| + begin 0x80000001 -4 0.866 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: + func -3 0.217 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: + func -3 0.225 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| + begin 0x80000001 -3 0.270 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| + end 0x80000001 -3 0.217 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: + func -3 0.540 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: + func -2 0.397 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: + func -2 0.337 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: + func -1 0.202 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: + func -1 0.191 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| + begin 0x80000001 -1 0.877 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| # func 0 0.270 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| + end 0x80000001 0 0.221 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< + freeze 0x004439ec 0 0.232 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| + begin 0x80000001 0 0.262 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| + end 0x80000001 0 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| + begin 0x80000001 0 0.367 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+ func 1 0.213 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+ func 1 0.195 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| + begin 0x80000001 1 0.270 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| + end 0x80000001 1 0.214 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+ func 1 0.225 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+ func 2 0.191 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+ func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 14:54 edward.robbins
@ 2010-10-23 15:37 ` Gilles Chanteperdrix
2010-10-23 16:21 ` edward.robbins
2010-10-23 16:13 ` Gilles Chanteperdrix
1 sibling, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 15:37 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Forgot to copy the list:
>
>
> Okay, so smi.c does not appear to contain my the PCI ID of my LPC chip. Motherboard has intel GS45 chipset, and "lspci -nn" says:
>
> 00:1f.0 ISA bridge [0601]: Intel Corporation ICH9M-E LPC Interface Controller [8086:2917] (rev 03)
>
> Is this what I'm looking for? (What has ISA got to do with this?)
>
> This PCI ID is not defined in either include/linux/pci_ids.h or include/asm-generic/xenomai/pci_ids.h, although there are these entries:
>
> PCI_DEVICE_ID_INTEL_ICH9_7 0x2916
> PCI_DEVICE_ID_INTEL_ICH9_8 0x2918
>
> So I guess I should add
>
> #define PCI_DEVICE_ID_INTEL_ICH9_9 0x2917
The define exists in include/linux/pci_ids.h as PCI_DEVICE_ID_INTEL_ICH9_1
Adding it to xenoami/pci_ids.s is only useful if you are using an older
kernel which has not got this define. 2.6.33 here has it.
>
> to xenomai/pci_ids.h, then add this define to smi.c, and see if magic happens?
>
> Thanks for walking me through this!
>
> Edward
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 14:54 edward.robbins
2010-10-23 15:37 ` Gilles Chanteperdrix
@ 2010-10-23 16:13 ` Gilles Chanteperdrix
2010-10-23 16:22 ` Gilles Chanteperdrix
1 sibling, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 16:13 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> Forgot to copy the list:
>
>
> Okay, so smi.c does not appear to contain my the PCI ID of my LPC
> chip. Motherboard has intel GS45 chipset, and "lspci -nn" says:
>
> 00:1f.0 ISA bridge [0601]: Intel Corporation ICH9M-E LPC Interface
> Controller [8086:2917] (rev 03)
>
> Is this what I'm looking for? (What has ISA got to do with this?)
The address of the register used to disable the SMIs is stored in the
PCI configuration space of this PCI peripheral. This address is an
io-port address, so, technically the ISA bus is used to disable the
SMIs. "LPC", means low pin count, which, I think refer to the wayq this
peripheral is wired somewhere.
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 15:37 ` Gilles Chanteperdrix
@ 2010-10-23 16:21 ` edward.robbins
2010-10-23 16:26 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-23 16:21 UTC (permalink / raw)
To: xenomai
>> So I guess I should add
>>
>> #define PCI_DEVICE_ID_INTEL_ICH9_9 0x2917
>
> The define exists in include/linux/pci_ids.h as PCI_DEVICE_ID_INTEL_ICH9_1
>
> Adding it to xenoami/pci_ids.s is only useful if you are using an older
> kernel which has not got this define. 2.6.33 here has it.
>
Okay, I'm using 2.6.32, but it exists here too, don't know how I missed it.
Just finished installing kernel.. booting now, ready to dohell ;)
Edward
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 16:13 ` Gilles Chanteperdrix
@ 2010-10-23 16:22 ` Gilles Chanteperdrix
0 siblings, 0 replies; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 16:22 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
Gilles Chanteperdrix wrote:
> edward.robbins@domain.hid wrote:
>> Forgot to copy the list:
>>
>>
>> Okay, so smi.c does not appear to contain my the PCI ID of my LPC
>> chip. Motherboard has intel GS45 chipset, and "lspci -nn" says:
>>
>> 00:1f.0 ISA bridge [0601]: Intel Corporation ICH9M-E LPC Interface
>> Controller [8086:2917] (rev 03)
>>
>> Is this what I'm looking for? (What has ISA got to do with this?)
>
> The address of the register used to disable the SMIs is stored in the
> PCI configuration space of this PCI peripheral. This address is an
> io-port address, so, technically the ISA bus is used to disable the
> SMIs. "LPC", means low pin count, which, I think refer to the wayq this
> peripheral is wired somewhere.
>
>
http://en.wikipedia.org/wiki/LPC_bus
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 16:21 ` edward.robbins
@ 2010-10-23 16:26 ` edward.robbins
2010-10-23 18:46 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-23 16:26 UTC (permalink / raw)
To: xenomai
Oh, and I got the SMI-enabled chipset found and SMI workaround enabled messages this time
On Saturday, 23 October, 2010 5:21pm, edward.robbins@domain.hidfordtechnologies.co.uk said:
>>> So I guess I should add
>>>
>>> #define PCI_DEVICE_ID_INTEL_ICH9_9 0x2917
>>
>> The define exists in include/linux/pci_ids.h as PCI_DEVICE_ID_INTEL_ICH9_1
>>
>> Adding it to xenoami/pci_ids.s is only useful if you are using an older
>> kernel which has not got this define. 2.6.33 here has it.
>>
>
> Okay, I'm using 2.6.32, but it exists here too, don't know how I missed it.
>
> Just finished installing kernel.. booting now, ready to dohell ;)
>
> Edward
>
>
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid> https://mail.gna.org/listinfo/xenomai-help
>
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 16:26 ` edward.robbins
@ 2010-10-23 18:46 ` edward.robbins
2010-10-23 21:52 ` Gilles Chanteperdrix
0 siblings, 1 reply; 38+ messages in thread
From: edward.robbins @ 2010-10-23 18:46 UTC (permalink / raw)
To: xenomai
[-- Attachment #1: Type: text/plain, Size: 2822 bytes --]
But no cigar...
Latency at 4491us, trace attached
I've supposedly got SMI disabled, MTRRs are disabled, ACPI processor disabled, CPU frequency scaling disabled, MSI and MSI-X disabled. I can't disable USB legacy in the BIOS because the option is grayed out (and no other options seem to make it work. I'm running through the troubleshooting file to see if there's anything else I can try but I can't see anything.
The BIOS has a ridiculous number of options, I have gone through and disabled most of them even though in many cases I'm really not sure what it is that they do - I just hope they don't cause anything to melt:
CRID, disabled memory thermal management,
turned off lots of ACPI and power options -
C2, C3, S4 wakeup from RTC, Trusted Execution Technology, P-States, Thermal Mode, C-States, C-State Pop Up Mode, C-State Pop Down Mode, DeepC4, Hard C4E, C6 Enhanced Multi Threaded Thermal Monitoring (EMTTM), Bi-directional PROCHOT, Dynamic FSB Switching, Turbo Mode, ACPI 3.0 T-States, CPU Digital Thermal Sensor, PCI Clock Run, Storage Break Event, PCIE Break Event, PCI Break Event, EHCI Break Event, UHCI Break Event, HDA Break Event, ACPI S3, wake on PME and set "ACPI Selection" from Acpi3.0 to Acpi1.0B in the hope it will be better supported.
I'm at a bit of a loss. Next I will try to figure out how to read the traces. The latency consistently jumps from <20us (normally around 14/15) to just under 4500us each time I run the test, so I am wondering if it is some specific thing that takes this long. I will also try to read the LTP output to see what it's doing when it fails, and see if this is consistent.
Gilles, I really appreciate all the help, thank you.
Anyone got any ideas?
On Saturday, 23 October, 2010 5:26pm, edward.robbins@domain.hid said:
> Oh, and I got the SMI-enabled chipset found and SMI workaround enabled messages
> this time
>
> On Saturday, 23 October, 2010 5:21pm, edward.robbins@domain.hid
> said:
>
>>>> So I guess I should add
>>>>
>>>> #define PCI_DEVICE_ID_INTEL_ICH9_9 0x2917
>>>
>>> The define exists in include/linux/pci_ids.h as PCI_DEVICE_ID_INTEL_ICH9_1
>>>
>>> Adding it to xenoami/pci_ids.s is only useful if you are using an older
>>> kernel which has not got this define. 2.6.33 here has it.
>>>
>>
>> Okay, I'm using 2.6.32, but it exists here too, don't know how I missed it.
>>
>> Just finished installing kernel.. booting now, ready to dohell ;)
>>
>> Edward
>>
>>
>> _______________________________________________
>> Xenomai-help mailing list
>> Xenomai-help@domain.hid>> https://mail.gna.org/listinfo/xenomai-help
>>
>
>
>
> _______________________________________________
> Xenomai-help mailing list
> Xenomai-help@domain.hid
> https://mail.gna.org/listinfo/xenomai-help
>
[-- Attachment #2: ipipe_trace.txt --]
[-- Type: text/plain, Size: 10729 bytes --]
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 2866098126420 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
: #func -4498 0.202 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -4498 0.247 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4498 0.255 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -4497 0.228 security_msg_msg_alloc+0x4 (load_msg+0xf9)
: +func -4497 0.232 cap_msg_msg_alloc_security+0x4 (security_msg_msg_alloc+0x16)
: +func -4497 0.206 ipc_lock_check+0x9 (do_msgsnd+0xa0)
: +func -4497 0.195 ipc_lock+0xb (ipc_lock_check+0x15)
: +func -4497 0.202 add_preempt_count+0x9 (ipc_lock+0x20)
: +func -4496 0.195 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| +begin 0x80000001 -4496 0.266 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| +end 0x80000001 -4496 0.251 ipipe_check_context+0xda (add_preempt_count+0x1c)
: +func -4496 0.195 _spin_lock+0x9 (ipc_lock+0x49)
: +func -4495 0.198 add_preempt_count+0x9 (_spin_lock+0x1b)
: +func -4495 0.195 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| +begin 0x80000001 -4495 0.266 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| +end 0x80000001 -4495 0.258 ipipe_check_context+0xda (add_preempt_count+0x1c)
: +func -4495 0.195 ipcperms+0xb (do_msgsnd+0xe9)
: +func -4494 0.191 security_ipc_permission+0x4 (ipcperms+0xab)
: +func -4494 0.195 cap_ipc_permission+0x4 (security_ipc_permission+0x19)
: +func -4494 0.210 security_msg_queue_msgsnd+0x4 (do_msgsnd+0xff)
: +func -4494 0.225 cap_msg_queue_msgsnd+0x4 (security_msg_queue_msgsnd+0x16)
: +func -4494 0.191 ipc_rcu_getref+0x4 (do_msgsnd+0x175)
: +func -4493 0.195 _spin_unlock+0x4 (do_msgsnd+0x17d)
: +func -4493 0.195 sub_preempt_count+0x9 (_spin_unlock+0x15)
: +func -4493 0.191 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -4493 0.258 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -4492 0.214 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -4492 0.191 sub_preempt_count+0x9 (do_msgsnd+0x187)
: +func -4492 0.187 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -4492 0.251 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -4492 0.217 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -4491 0.195 schedule+0x14 (do_msgsnd+0x1a1)
: +func -4491 0.191 add_preempt_count+0x9 (schedule+0x64)
: +func -4491 0.202 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| +begin 0x80000001 -4491 0.255 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| +end 0x80000001 -4491 0.217 ipipe_check_context+0xda (add_preempt_count+0x1c)
:| +begin 0x80000001 -4490 0.232 debug_smp_processor_id+0x44 (schedule+0x69)
:| +end 0x80000001 -4490 0.210 debug_smp_processor_id+0x94 (schedule+0x69)
: +func -4490 0.232 rcu_sched_qs+0x4 (schedule+0x8b)
: +func -4490 0.195 ipipe_check_context+0x11 (schedule+0x124)
:| +begin 0x80000001 -4490 0.255 ipipe_check_context+0x33 (schedule+0x124)
:| +end 0x80000001 -4489 0.210 ipipe_check_context+0xda (schedule+0x124)
: +func -4489 0.191 _spin_lock_irq+0x9 (schedule+0x195)
: +func -4489 0.187 ipipe_check_context+0x11 (_spin_lock_irq+0x1d)
:| +begin 0x80000001 -4489 0.251 ipipe_check_context+0x33 (_spin_lock_irq+0x1d)
:| +end 0x80000001 -4488 0.236 ipipe_check_context+0xda (_spin_lock_irq+0x1d)
: #func -4488 0.206 add_preempt_count+0x9 (_spin_lock_irq+0x3f)
: #func -4488 0.199 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -4488 0.243 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -4488! 4468.801 ipipe_check_context+0xda (add_preempt_count+0x1c)
:| #begin 0x000000f6 -19 0.229 common_interrupt+0x20 (sched_clock_cpu+0x37)
:| #func -18 0.247 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| #func -18 0.206 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| #func -18 0.202 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| #func -18 0.229 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| #func -18 0.217 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| #func -17 0.277 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| #*func -17 0.247 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| #*func -17 0.442 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| #*func -16 0.202 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| #*func -16 0.217 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| #*[ 3286] samplin 99 -16 0.420 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| #*func -16 0.198 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| #*event tick@32 -15 0.202 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| #*func -15 0.251 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| #*func -15 0.277 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| #*[25914] -<?>- -1 -15 0.221 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| #*func -14 0.416 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -14 0.521 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*[ 3286] samplin 99 -13 0.375 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -13 0.251 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -13 0.225 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -13 0.517 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x00000039 -12 0.243 common_interrupt+0x20 (__ipipe_restore_pipeline_head+0x139)
:| +*func -12 0.664 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| +*func -11 0.333 __ipipe_set_irq_pending+0xd (__ipipe_handle_irq+0x173)
:| +*func -11 0.206 irq_to_desc+0x4 (__ipipe_handle_irq+0x18b)
:| +*func -11 0.322 __ipipe_ack_fasteoi_irq+0x4 (__ipipe_handle_irq+0x194)
:| +*func -10 0.285 ack_apic_level+0xd (__ipipe_ack_fasteoi_irq+0x10)
:| +*func -10 0.225 native_apic_mem_read+0x4 (ack_apic_level+0x4d)
:| +*func -10+ 2.051 io_apic_modify_irq+0xb (ack_apic_level+0xb6)
:| +*func -8+ 1.432 io_apic_sync+0x4 (io_apic_modify_irq+0x9e)
:| +*func -6 0.292 native_apic_mem_write+0x4 (ack_apic_level+0xd0)
:| +*end 0x00000039 -6 0.469 common_interrupt+0x39 (__ipipe_restore_pipeline_head+0x139)
:| +*begin 0x80000001 -6 0.311 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -5 0.236 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -5+ 1.593 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -3 0.225 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -3 0.191 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -3 0.270 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -3 0.217 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -3 0.562 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -2 0.453 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: +*func -2 0.334 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: +*func -1 0.202 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: +*func -1 0.198 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| +*begin 0x80000001 -1 0.784 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| #*func 0 0.262 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| +*end 0x80000001 0 0.251 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< +*freeze 0x004412b3 0 0.225 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| +*begin 0x80000001 0 0.262 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 0 0.225 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 0 0.390 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.225 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.199 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 1 0.277 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 1 0.206 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+*func 2 0.225 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+*func 2 0.195 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+*func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
[-- Attachment #3: ipipe_trace2.txt --]
[-- Type: text/plain, Size: 10906 bytes --]
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 3030879662150 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
:| +end 0x80000001 -4519 0.206 debug_smp_processor_id+0x94 (try_to_wake_up+0x3d)
: +func -4519 0.202 task_rq_lock+0xb (try_to_wake_up+0x49)
: +func -4518 0.199 ipipe_check_context+0x11 (task_rq_lock+0x29)
:| +begin 0x80000001 -4518 0.247 ipipe_check_context+0x33 (task_rq_lock+0x29)
:| +end 0x80000001 -4518 0.240 ipipe_check_context+0xda (task_rq_lock+0x29)
: #func -4518 0.206 _spin_lock+0x9 (task_rq_lock+0x6c)
: #func -4518 0.199 add_preempt_count+0x9 (_spin_lock+0x1b)
: #func -4517 0.198 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -4517 0.251 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -4517 0.258 ipipe_check_context+0xda (add_preempt_count+0x1c)
:| #begin 0x80000001 -4517 0.225 debug_smp_processor_id+0x44 (sched_clock_cpu+0x92)
:| #end 0x80000001 -4516 0.225 debug_smp_processor_id+0x94 (sched_clock_cpu+0x92)
:| #begin 0x80000001 -4516 0.225 debug_smp_processor_id+0x44 (native_sched_clock+0x37)
:| #end 0x80000001 -4516 0.236 debug_smp_processor_id+0x94 (native_sched_clock+0x37)
: #func -4516 0.206 _spin_unlock_irqrestore+0x4 (try_to_wake_up+0xc3)
: #func -4516 0.195 __ipipe_restore_root+0xb (_spin_unlock_irqrestore+0x21)
:| #begin 0x80000001 -4515 0.225 __ipipe_restore_root+0x2d (_spin_unlock_irqrestore+0x21)
:| #end 0x80000001 -4515 0.232 __ipipe_restore_root+0x7d (_spin_unlock_irqrestore+0x21)
: #func -4515 0.199 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -4515 0.255 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -4514 0.202 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -4514 0.210 sub_preempt_count+0x9 (_spin_unlock_irqrestore+0x2b)
: +func -4514 0.198 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -4514 0.255 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -4514 0.217 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -4513 0.232 select_task_rq_fair+0x14 (try_to_wake_up+0xd5)
:| +begin 0x80000001 -4513 0.229 debug_smp_processor_id+0x44 (select_task_rq_fair+0x31)
:| +end 0x80000001 -4513 0.236 debug_smp_processor_id+0x94 (select_task_rq_fair+0x31)
: +func -4513 0.191 add_preempt_count+0x9 (select_task_rq_fair+0xba)
: +func -4512 0.206 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| +begin 0x80000001 -4512 0.251 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| +end 0x80000001 -4512 0.315 ipipe_check_context+0xda (add_preempt_count+0x1c)
: +func -4512 0.206 update_shares+0x9 (select_task_rq_fair+0x34d)
:| +begin 0x80000001 -4512 0.232 debug_smp_processor_id+0x44 (select_task_rq_fair+0x39c)
:| +end 0x80000001 -4511 0.225 debug_smp_processor_id+0x94 (select_task_rq_fair+0x39c)
: +func -4511 0.202 effective_load+0x4 (select_task_rq_fair+0x528)
: +func -4511 0.236 effective_load+0x4 (select_task_rq_fair+0x53c)
: +func -4511 0.198 sub_preempt_count+0x9 (select_task_rq_fair+0x8bf)
: +func -4510 0.191 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -4510 0.255 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -4510 0.225 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -4510 0.191 task_rq_lock+0xb (try_to_wake_up+0xef)
: +func -4510 0.187 ipipe_check_context+0x11 (task_rq_lock+0x29)
:| +begin 0x80000001 -4509 0.251 ipipe_check_context+0x33 (task_rq_lock+0x29)
:| +end 0x80000001 -4509 0.232 ipipe_check_context+0xda (task_rq_lock+0x29)
: #func -4509 0.206 _spin_lock+0x9 (task_rq_lock+0x6c)
: #func -4509 0.199 add_preempt_count+0x9 (_spin_lock+0x1b)
: #func -4508 0.202 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -4508 0.251 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -4508! 4488.026 ipipe_check_context+0xda (add_preempt_count+0x1c)
:| #begin 0x000000f6 -20 0.236 common_interrupt+0x20 (task_rq_lock+0x73)
:| #func -20 0.247 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| #func -20 0.214 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| #func -19 0.187 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| #func -19 0.225 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| #func -19 0.221 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| #func -19 0.274 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| #*func -18 0.251 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| #*func -18 0.574 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| #*func -18 0.191 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| #*func -17 0.217 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| #*[ 3274] -<?>- 99 -17 0.457 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| #*func -17 0.199 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| #*event tick@2 -16 0.202 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| #*func -16 0.247 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| #*func -16 0.270 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| #*[25498] -<?>- -1 -16 0.221 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| #*func -16 0.412 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -15 0.514 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*[ 3274] -<?>- 99 -15 0.367 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -14 0.247 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -14 0.225 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -14 0.585 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x00000039 -13 0.247 common_interrupt+0x20 (__ipipe_restore_pipeline_head+0x139)
:| +*func -13 0.686 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| +*func -12 0.337 __ipipe_set_irq_pending+0xd (__ipipe_handle_irq+0x173)
:| +*func -12 0.450 irq_to_desc+0x4 (__ipipe_handle_irq+0x18b)
:| +*func -11 0.517 __ipipe_ack_fasteoi_irq+0x4 (__ipipe_handle_irq+0x194)
:| +*func -11 0.364 ack_apic_level+0xd (__ipipe_ack_fasteoi_irq+0x10)
:| +*func -11 0.412 native_apic_mem_read+0x4 (ack_apic_level+0x4d)
:| +*func -10+ 2.198 io_apic_modify_irq+0xb (ack_apic_level+0xb6)
:| +*func -8+ 1.440 io_apic_sync+0x4 (io_apic_modify_irq+0x9e)
:| +*func -7 0.288 native_apic_mem_write+0x4 (ack_apic_level+0xd0)
:| +*end 0x00000039 -6 0.465 common_interrupt+0x39 (__ipipe_restore_pipeline_head+0x139)
:| +*begin 0x80000001 -6 0.277 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -6 0.210 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -5+ 1.774 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -4 0.217 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -3 0.195 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -3 0.270 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -3 0.213 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -3 0.544 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -2 0.442 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: +*func -2 0.318 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: +*func -1 0.199 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: +*func -1 0.206 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| +*begin 0x80000001 -1 0.889 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| #*func 0 0.281 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| +*end 0x80000001 0 0.251 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< +*freeze 0x004488c6 0 0.236 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| +*begin 0x80000001 0 0.266 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 0 0.225 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 0 0.386 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.251 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.213 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 1 0.281 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 1 0.213 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+*func 2 0.232 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+*func 2 0.206 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+*func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 18:46 ` edward.robbins
@ 2010-10-23 21:52 ` Gilles Chanteperdrix
2010-10-24 15:55 ` edward.robbins
0 siblings, 1 reply; 38+ messages in thread
From: Gilles Chanteperdrix @ 2010-10-23 21:52 UTC (permalink / raw)
To: edward.robbins; +Cc: xenomai
edward.robbins@domain.hid wrote:
> But no cigar...
>
> Latency at 4491us, trace attached
>
> I've supposedly got SMI disabled, MTRRs are disabled, ACPI processor
> disabled, CPU frequency scaling disabled, MSI and MSI-X disabled. I
> can't disable USB legacy in the BIOS because the option is grayed out
> (and no other options seem to make it work. I'm running through the
> troubleshooting file to see if there's anything else I can try but I
> can't see anything.
>
> The BIOS has a ridiculous number of options, I have gone through and
> disabled most of them even though in many cases I'm really not sure
> what it is that they do - I just hope they don't cause anything to
> melt:
>
> CRID, disabled memory thermal management, turned off lots of ACPI and
Pay attention not to disable ACPI completely, as this enables APM, the
legacy power management, and this one causes high latencies.
> power options - C2, C3, S4 wakeup from RTC, Trusted Execution
> Technology, P-States, Thermal Mode, C-States, C-State Pop Up Mode,
> C-State Pop Down Mode, DeepC4, Hard C4E, C6 Enhanced Multi Threaded
> Thermal Monitoring (EMTTM), Bi-directional PROCHOT, Dynamic FSB
> Switching, Turbo Mode, ACPI 3.0 T-States, CPU Digital Thermal Sensor,
> PCI Clock Run, Storage Break Event, PCIE Break Event, PCI Break
> Event, EHCI Break Event, UHCI Break Event, HDA Break Event, ACPI S3,
> wake on PME and set "ACPI Selection" from Acpi3.0 to Acpi1.0B in the
> hope it will be better supported.
>
> I'm at a bit of a loss. Next I will try to figure out how to read the
> traces. The latency consistently jumps from <20us (normally around
> 14/15) to just under 4500us each time I run the test, so I am
> wondering if it is some specific thing that takes this long. I will
> also try to read the LTP output to see what it's doing when it fails,
> and see if this is consistent.
>
> Gilles, I really appreciate all the help, thank you.
You are welcome, no problem. A few things to try: could you try and use
the latest I-pipe for 2.6.35? Just to rule out anything which would have
been fixed since 2.6.32.
Something else, did you try to run your system completely without
framebuffer and X-window? In good old text mode?
I do not know what more to suggest. The traces you sent show
consistently ipipe_check_context at the point where you have the issue,
I do not know whether this is a coincidence. Do you get any I-pipe
message in the kernel logs after the latency peak happens?
--
Gilles.
^ permalink raw reply [flat|nested] 38+ messages in thread
* Re: [Xenomai-help] Very high latencies under stress testing
2010-10-23 21:52 ` Gilles Chanteperdrix
@ 2010-10-24 15:55 ` edward.robbins
0 siblings, 0 replies; 38+ messages in thread
From: edward.robbins @ 2010-10-24 15:55 UTC (permalink / raw)
To: Gilles Chanteperdrix; +Cc: xenomai
>>
>> CRID, disabled memory thermal management, turned off lots of ACPI and
>
> Pay attention not to disable ACPI completely, as this enables APM, the
> legacy power management, and this one causes high latencies.
>
I'm pretty sure it's still enabled.
>>
>> I'm at a bit of a loss. Next I will try to figure out how to read the
>> traces. The latency consistently jumps from <20us (normally around
>> 14/15) to just under 4500us each time I run the test, so I am
>> wondering if it is some specific thing that takes this long. I will
>> also try to read the LTP output to see what it's doing when it fails,
>> and see if this is consistent.
>>
>> Gilles, I really appreciate all the help, thank you.
>
> You are welcome, no problem. A few things to try: could you try and use
> the latest I-pipe for 2.6.35? Just to rule out anything which would have
> been fixed since 2.6.32.
>
I did wonder if I should do this. I'll try that next, though I'm not sure when that will be.
> Something else, did you try to run your system completely without
> framebuffer and X-window? In good old text mode?
>
Yes, all these tests are with X disabled, I'm not even using framebuffer just straight console mode.
> I do not know what more to suggest. The traces you sent show
> consistently ipipe_check_context at the point where you have the issue,
> I do not know whether this is a coincidence. Do you get any I-pipe
> message in the kernel logs after the latency peak happens?
>
I'm fairly sure the answer is no, but will have to double check next time I'm working on the system.
^ permalink raw reply [flat|nested] 38+ messages in thread
end of thread, other threads:[~2010-10-24 15:55 UTC | newest]
Thread overview: 38+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2010-08-13 14:17 [Xenomai-help] Very high latencies under stress testing edward.robbins
2010-08-13 14:35 ` Gilles Chanteperdrix
2010-08-16 12:13 ` edward.robbins
2010-08-16 12:32 ` Gilles Chanteperdrix
2010-09-03 16:30 ` edward.robbins
2010-09-04 8:51 ` Philippe Gerum
2010-10-15 9:21 ` edward.robbins
2010-10-15 11:54 ` edward.robbins
2010-10-15 13:51 ` Gilles Chanteperdrix
2010-10-15 14:13 ` edward.robbins
2010-10-15 14:25 ` Gilles Chanteperdrix
2010-10-15 14:33 ` Philippe Gerum
2010-10-19 13:52 ` edward.robbins
2010-10-19 20:01 ` Gilles Chanteperdrix
2010-10-23 11:08 ` edward.robbins
2010-10-23 11:13 ` Gilles Chanteperdrix
2010-10-23 11:22 ` edward.robbins
2010-10-23 11:36 ` Gilles Chanteperdrix
2010-10-23 13:45 ` edward.robbins
2010-10-23 13:51 ` Gilles Chanteperdrix
2010-10-23 13:56 ` edward.robbins
2010-10-23 13:58 ` Gilles Chanteperdrix
2010-10-23 14:32 ` edward.robbins
2010-10-23 14:37 ` Gilles Chanteperdrix
2010-10-23 14:48 ` edward.robbins
2010-10-23 15:16 ` edward.robbins
2010-10-23 14:10 ` Gilles Chanteperdrix
2010-08-13 14:40 ` Philippe Gerum
2010-08-13 16:15 ` Philippe Gerum
-- strict thread matches above, loose matches on Subject: below --
2010-10-23 14:54 edward.robbins
2010-10-23 15:37 ` Gilles Chanteperdrix
2010-10-23 16:21 ` edward.robbins
2010-10-23 16:26 ` edward.robbins
2010-10-23 18:46 ` edward.robbins
2010-10-23 21:52 ` Gilles Chanteperdrix
2010-10-24 15:55 ` edward.robbins
2010-10-23 16:13 ` Gilles Chanteperdrix
2010-10-23 16:22 ` Gilles Chanteperdrix
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.