Re: [Xenomai-core] x86_64 - Initial results.
Hi Philippe
On Sunday 25 February 2007 22:00, Philippe Gerum wrote:
> > Results are still the same - Latency goes to pot and hangs as soon as X
> > starts up. Quite likely the offending trace isn't getting logged..
>
> Just for the purpose of digging the issue further, does this particular
> problem persist when MTRRs are switched off from the kernel config?
I'd just finished compiling yet another kernel with CONFIG_MTRR disabled and
was about to run another test..
Logs attached - Even with ipipe-trace enabled, latencies are acceptable when
firing up X/KDE..
Regards, Paul.
I-pipe frozen back-tracing service on 2.6.19.3-xenomai/ipipe-1.0-04
Freeze: 970774923862 cycles, Trace Points: 30 (+100)
Calibrated minimum trace-point overhead: 0.037 us
+- Hard IRQs ('|': locked)
|+
||+---
|||+-- Xenomai
+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
|+-- Delay flag ('+': > 1 us, '!': > 10 us)
||+- NMI noise ('N')
|||
TypeUser Val. TimeDelay Function (Parent)
:| # func -30.067 xnpod_schedule+0x16
(xnintr_irq_handler+0x116)
:| # [ 3008] Xorg-1-30.231 xnpod_schedule+0xa8
(xnintr_irq_handler+0x116)
:| # func -20.343 __switch_to+0x16 (xnpod_schedule+0x80b)
:| # [ 2716] samplin 99-20.134 xnpod_schedule+0x848
(xnpod_suspend_thread+0x154)
:| # func -20.065 __ipipe_restore_pipeline_head+0x16
(xnpod_wait_thread_period+0x11e)
:| + end 0x8000-20.163 __ipipe_restore_pipeline_head+0xb1
(xnpod_wait_thread_period+0x11e)
:| + begin 0x8001-20.073 __ipipe_dispatch_event+0xe9
(__ipipe_syscall_root+0x8d)
:| + end 0x8001-20.088 __ipipe_dispatch_event+0x191
(__ipipe_syscall_root+0x8d)
:| + begin 0x8000-20.326 __ipipe_syscall_root+0x14b
(__ipipe_syscall_root_thunk+0x35)
: + func -10.076 __ipipe_syscall_root+0xc
(__ipipe_syscall_root_thunk+0x35)
: + func -10.071 __ipipe_dispatch_event+0x16
(__ipipe_syscall_root+0x8d)
:| + begin 0x8001-10.048 __ipipe_dispatch_event+0x37
(__ipipe_syscall_root+0x8d)
:| + end 0x8001-10.070 __ipipe_dispatch_event+0xb6
(__ipipe_syscall_root+0x8d)
: + func -10.098 hisyscall_event+0x21
(__ipipe_dispatch_event+0xc7)
: + func -10.077 __rt_timer_tsc2ns+0xe [xeno_native]
(hisyscall_event+0x1bb)
: + func -10.144 rt_timer_tsc2ns+0x9 [xeno_native]
(__rt_timer_tsc2ns+0x2c [xeno_native])
:| + begin 0x8001-10.072 __ipipe_dispatch_event+0xe9
(__ipipe_syscall_root+0x8d)
:| + end 0x8001-10.078 __ipipe_dispatch_event+0x191
(__ipipe_syscall_root+0x8d)
:| + begin 0x8000 00.139 __ipipe_syscall_root+0x14b
(__ipipe_syscall_root_thunk+0x35)
: + func 00.063 __ipipe_syscall_root+0xc
(__ipipe_syscall_root_thunk+0x35)
: + func 00.064 __ipipe_dispatch_event+0x16
(__ipipe_syscall_root+0x8d)
:| + begin 0x8001 00.056 __ipipe_dispatch_event+0x37
(__ipipe_syscall_root+0x8d)
:| + end 0x8001 00.061 __ipipe_dispatch_event+0xb6
(__ipipe_syscall_root+0x8d)
: + func 00.151 hisyscall_event+0x21
(__ipipe_dispatch_event+0xc7)
: + func 00.059 xnshadow_sys_trace+0x16
(hisyscall_event+0x1bb)
: + func 00.127 ipipe_trace_frozen_reset+0xa
(xnshadow_sys_trace+0x8a)
: + func 00.051 __ipipe_global_path_lock+0xa
(ipipe_trace_frozen_reset+0x14)
:| + begin 0x8001 00.120 __ipipe_global_path_lock+0x1c
(ipipe_trace_frozen_reset+0x14)
:| + end 0x8001 00.066 __ipipe_global_path_unlock+0x62
(ipipe_trace_frozen_reset+0x61)
< + freeze 0x543e 00.084 xnshadow_sys_trace+0x94
(hisyscall_event+0x1bb)
| + begin 0x8001 00.062 __ipipe_dispatch_event+0xe9
(__ipipe_syscall_root+0x8d)
| + end 0x8001 00.083 __ipipe_dispatch_event+0x191
(__ipipe_syscall_root+0x8d)
| + begin 0x8000 00.131 __ipipe_syscall_root+0x14b
(__ipipe_syscall_root_thunk+0x35)
+ func 00.066 __ipipe_syscall_root+0xc
(__ipipe_syscall_root_thunk+0x35)
+ func 00.064 __ipipe_dispatch_event+0x16
(__ipipe_syscall_root+0x8d)
| + begin 0x8001 00.057 __ipipe_dispatch_event+0x37
(__ipipe_syscall_root+0x8d)
| + end 0x8001 00.071 __ipipe_dispatch_event+0xb6
(__ipipe_syscall_root+0x8d)
+ func 00.083 hisyscall_event+0x21
(__ipipe_dispatch_event+0xc7)
+ func 00.048 __rt_task_wait_per
Re: [Xenomai-core] x86_64 - Initial results.
On Sun, 2007-02-25 at 18:42 +, Paul wrote: > Results are still the same - Latency goes to pot and hangs as soon as X > starts > up. Quite likely the offending trace isn't getting logged.. > Just for the purpose of digging the issue further, does this particular problem persist when MTRRs are switched off from the kernel config? -- Philippe. ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
Re: [Xenomai-core] x86_64 - Initial results.
Paul wrote:
> On Sunday 25 February 2007 16:03, Jan Kiszka wrote:
>>> The attached trace logs provide little information - Also included dmesg
>> One more try please: we also need CONFIG_IPIPE_TRACE_MCOUNT.
>
> With both CONFIG_IPIPE_TRACE_MCOUNT and CONFIG_IPIPE_TRACE_VMALLOC enabled,
> the system auto-reboots as soon as the kernel starts to uncompress. Disabling
> the latter restores normal service.
Are we still tracing too early during boot? Probably worth a qemu/gdb
session.
>
> On Sunday 25 February 2007 16:09, Gilles Chanteperdrix wrote:
>> Option "NoAccel"
>
> Results are still the same - Latency goes to pot and hangs as soon as X
> starts
> up. Quite likely the offending trace isn't getting logged..
>
>
...
>
>
> I-pipe frozen back-tracing service on 2.6.19.3-xenomai/ipipe-1.0-04
>
> Freeze: 434598593698 cycles, Trace Points: 30 (+100)
> Calibrated minimum trace-point overhead: 0.037 us
>
> +- Hard IRQs ('|': locked)
> |+
> ||+---
> |||+-- Xenomai
> +- Linux ('*': domain stalled, '+': current, '#': current+stalled)
> |+-- Delay flag ('+': > 1 us, '!': > 10
> us)
> ||+- NMI noise ('N')
> |||
> TypeUser Val. TimeDelay Function (Parent)
> :| +*func-244+ 6.981 __ipipe_handle_irq+0x21
> (common_interrupt+0x78)
> :| +*func-238+ 6.956 __ipipe_ack_apic+0x9
> (__ipipe_handle_irq+0x87)
> :| +*func-231+ 7.615 __ipipe_dispatch_wired+0xc
> (__ipipe_handle_irq+0x91)
> :| #*func-223+ 6.951 xnintr_clock_handler+0x9
> (__ipipe_dispatch_wired+0x94)
> :| #*func-216+ 7.210 xnintr_irq_handler+0x21
> (xnintr_clock_handler+0x1b)
Given these *huge* latencies for that simple functions, we are may face
some CPU frequency screw (though scaling is switched off?). Something
must disturb the tsc->ns conversion. Maybe this is actually no latency
real issue...
Jan
signature.asc
Description: OpenPGP digital signature
___
Xenomai-core mailing list
Xenomai-core@gna.org
https://mail.gna.org/listinfo/xenomai-core
Re: [Xenomai-core] x86_64 - Initial results.
On Sunday 25 February 2007 16:03, Jan Kiszka wrote: > > The attached trace logs provide little information - Also included dmesg > > One more try please: we also need CONFIG_IPIPE_TRACE_MCOUNT. With both CONFIG_IPIPE_TRACE_MCOUNT and CONFIG_IPIPE_TRACE_VMALLOC enabled, the system auto-reboots as soon as the kernel starts to uncompress. Disabling the latter restores normal service. On Sunday 25 February 2007 16:09, Gilles Chanteperdrix wrote: > Option "NoAccel" Results are still the same - Latency goes to pot and hangs as soon as X starts up. Quite likely the offending trace isn't getting logged.. Regards, Paul. [0.00] Linux version 2.6.19.3-xenomai ([EMAIL PROTECTED]) (gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)) #7 Sun Feb 25 17:58:53 GMT 2007 [0.00] Command line: root=/dev/sda2 ro splash=silent vga=788 [0.00] BIOS-provided physical RAM map: [0.00] BIOS-e820: - 0009fc00 (usable) [0.00] BIOS-e820: 0009fc00 - 000a (reserved) [0.00] BIOS-e820: 000e4000 - 0010 (reserved) [0.00] BIOS-e820: 0010 - 1ffb (usable) [0.00] BIOS-e820: 1ffb - 1ffc (ACPI data) [0.00] BIOS-e820: 1ffc - 1fff (ACPI NVS) [0.00] BIOS-e820: 1fff - 2000 (reserved) [0.00] BIOS-e820: ff78 - 0001 (reserved) [0.00] Entering add_active_range(0, 0, 159) 0 entries of 256 used [0.00] Entering add_active_range(0, 256, 130992) 1 entries of 256 used [0.00] end_pfn_map = 1048576 [0.00] DMI 2.3 present. [0.00] ACPI: RSDP (v000 ACPIAM) @ 0x000fa810 [0.00] ACPI: RSDT (v001 A M I OEMRSDT 0x01000723 MSFT 0x0097) @ 0x1ffb [0.00] ACPI: FADT (v001 A M I OEMFACP 0x01000723 MSFT 0x0097) @ 0x1ffb0200 [0.00] ACPI: MADT (v001 A M I OEMAPIC 0x01000723 MSFT 0x0097) @ 0x1ffb0390 [0.00] ACPI: OEMB (v001 A M I OEMBIOS 0x01000723 MSFT 0x0097) @ 0x1ffc0040 [0.00] ACPI: DSDT (v001 A0277 A0277001 0x0001 MSFT 0x010d) @ 0x [0.00] Entering add_active_range(0, 0, 159) 0 entries of 256 used [0.00] Entering add_active_range(0, 256, 130992) 1 entries of 256 used [0.00] Zone PFN ranges: [0.00] DMA 0 -> 4096 [0.00] DMA324096 -> 1048576 [0.00] Normal1048576 -> 1048576 [0.00] early_node_map[2] active PFN ranges [0.00] 0:0 -> 159 [0.00] 0: 256 -> 130992 [0.00] On node 0 totalpages: 130895 [0.00] DMA zone: 56 pages used for memmap [0.00] DMA zone: 1700 pages reserved [0.00] DMA zone: 2243 pages, LIFO batch:0 [0.00] DMA32 zone: 1734 pages used for memmap [0.00] DMA32 zone: 125162 pages, LIFO batch:31 [0.00] Normal zone: 0 pages used for memmap [0.00] ACPI: PM-Timer IO Port: 0x808 [0.00] ACPI: Local APIC address 0xfee0 [0.00] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled) [0.00] Processor #0 (Bootup-CPU) [0.00] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled) [0.00] Processor #1 [0.00] WARNING: NR_CPUS limit of 1 reached. Processor ignored. [0.00] ACPI: IOAPIC (id[0x02] address[0xfec0] gsi_base[0]) [0.00] IOAPIC[0]: apic_id 2, address 0xfec0, GSI 0-23 [0.00] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) [0.00] ACPI: IRQ0 used by override. [0.00] ACPI: IRQ2 used by override. [0.00] ACPI: IRQ9 used by override. [0.00] Setting APIC routing to flat [0.00] Using ACPI (MADT) for SMP configuration information [0.00] Nosave address range: 0009f000 - 000a [0.00] Nosave address range: 000a - 000e4000 [0.00] Nosave address range: 000e4000 - 0010 [0.00] Allocating PCI resources starting at 3000 (gap: 2000:df78) [0.00] Built 1 zonelists. Total pages: 127405 [0.00] Kernel command line: root=/dev/sda2 ro splash=silent vga=788 [0.00] Initializing CPU#0 [0.00] PID hash table entries: 2048 (order: 11, 16384 bytes) [ 28.777403] time.c: Using 3.579545 MHz WALL PM GTOD PIT/TSC timer. [ 28.777410] time.c: Detected 2403.177 MHz processor. [ 28.777485] I-pipe 1.0-04: pipeline enabled. [ 28.777553] Console: colour dummy device 80x25 [ 28.778250] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes) [ 28.778657] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes) [ 28.778737] Checking aperture... [ 28.778745] CPU 0: aperture @ f000 size 64 MB [ 28.786774] Memory: 502760k/523968k av
Re: [Xenomai-core] x86_64 - Initial results.
Paul wrote: > On Sunday 25 February 2007 10:02, Jan Kiszka wrote: > > >> Rather the CONFIG_IPIPE_TRACE feature, with the IRQs off tracking option > > >> set > > > Please grab trace/frozen instead, enable verbose mode, and increase > > back_trace_points so that the reported latency is fully covered. See > > OK - Recompiled with the 1.04 patch for UP with the ipipe trace support. > After > cutting Xorg's configs to a minimum (vesa driver, no Glx/dri > support), If you want to disable X acceleration, you should add : Option "NoAccel" in the "Device" section of your X configuration file. > latency runs OK and reports some pretty horrible numbers when X starts (no > WM). Enabling the tracer, and starting/stopping X, the system either locks > up > or latency goes in to a zombie state. > > The attached trace logs provide little information - Also included dmesg > and > kernel config. -- Gilles Chanteperdrix. ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
Re: [Xenomai-core] x86_64 - Initial results.
Paul wrote: > On Sunday 25 February 2007 10:02, Jan Kiszka wrote: Rather the CONFIG_IPIPE_TRACE feature, with the IRQs off tracking option set > >> Please grab trace/frozen instead, enable verbose mode, and increase >> back_trace_points so that the reported latency is fully covered. See > > OK - Recompiled with the 1.04 patch for UP with the ipipe trace support. > After > cutting Xorg's configs to a minimum (vesa driver, no Glx/dri support), > latency runs OK and reports some pretty horrible numbers when X starts (no > WM). Enabling the tracer, and starting/stopping X, the system either locks up > or latency goes in to a zombie state. > > The attached trace logs provide little information - Also included dmesg and > kernel config. One more try please: we also need CONFIG_IPIPE_TRACE_MCOUNT. Jan signature.asc Description: OpenPGP digital signature ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
Re: [Xenomai-core] x86_64 - Initial results.
Paul wrote: > Hi Philippe > > On Saturday 24 February 2007 17:17, Philippe Gerum wrote: Ok, the latter looks clearly pathological. The trace should tell us more. > >> Rather the CONFIG_IPIPE_TRACE feature, with the IRQs off tracking option >> set > > > Had to recompile without SMP (see attached config), so used the -03 ipipe > patch with xenomai r2248. Started the latency test, and then fired up X (no > WM) - At which point the latency went in to a zombie state with a massive > hike in value. ipipe/trace/max, latency log, and dmesg outputs all attached. > Please grab trace/frozen instead, enable verbose mode, and increase back_trace_points so that the reported latency is fully covered. See http://www.xenomai.org/index.php/I-pipe:Tracer for further instructions. Thanks, Jan signature.asc Description: OpenPGP digital signature ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
Re: [Xenomai-core] x86_64 - Initial results.
On Sat, 2007-02-24 at 16:55 +, Paul wrote: > On Saturday 24 February 2007 15:56, Philippe Gerum wrote: > > > Initial results look promising with the latency test reporting figures > > > in the 0.5 to 4 uSec range under light load. A kernel compile bumps the > > > wost up to 9-14uSec. > > > > Not bad. Is this a UP or SMP config, and which kind of box did run the > > tests precisely? > > AMD X2 4600+ with SMP config - MoBo is an Asus A8V with a Via K8T800Pro > chipset and a measly 512M of RAM. > Ok. > > > Firing up X,KDE, and a gamut of desktop apps really kills the > > > numbers though - ~267uSec being the worst recorded so far, > > > > Ok, the latter looks clearly pathological. The trace should tell us > > more. > > The latency log ? Rather the CONFIG_IPIPE_TRACE feature, with the IRQs off tracking option set, but the latency log already has some value, thanks. > Attached is some three hours worth of log - Should point out there are no > proprietory video drivers being used, just the regular Xorg stuff and what > ever the kernel provides. > Looking at this log, the good news is that latency peaks are not spread all over the place, but only a few of them are bugging us. This tend to confirm a bad interference exists with something specific to the X startup procedure (maybe/likely? related to the graphic card). Does the peak still occur if you disable hw acceleration for the graphic card in your XF86Config file? > > Regards, Paul. > -- Philippe. ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
Re: [Xenomai-core] x86_64 - Initial results.
On Sat, 2007-02-24 at 15:26 +, Paul wrote: > Hi Philippe > > First off, thanks for all your hard work and late nights (and the rest of > the > team) for the x86_64. > > Initial results look promising with the latency test reporting figures in > the > 0.5 to 4 uSec range under light load. A kernel compile bumps the wost up to > 9-14uSec. Not bad. Is this a UP or SMP config, and which kind of box did run the tests precisely? > Firing up X,KDE, and a gamut of desktop apps really kills the > numbers though - ~267uSec being the worst recorded so far, Ok, the latter looks clearly pathological. The trace should tell us more. > however, once > X/KDE has started up, latencies are generally <30uSec. > > One small problem to report from the compile... With > CONFIG_XENO_OPT_NUCLEUS=m, the build fails with: > > WARNING: "cpu_gdt_descr" [kernel/xenomai/nucleus/xeno_nucleus.ko] undefined! > make[1]: *** [__modpost] Error 1 > > What would the preferred solution be - Export cpu_gdt_descr as it is with > i386, or force xeno_nucleus to be built in ? > We can export it, it's already a global symbol anyway. I've now added the proper EXPORT_SYMBOL_GPL in my local repo. Thanks for pointing this out. > > Regards, Paul. > > ___ > Xenomai-core mailing list > Xenomai-core@gna.org > https://mail.gna.org/listinfo/xenomai-core -- Philippe. ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
[Xenomai-core] x86_64 - Initial results.
Hi Philippe First off, thanks for all your hard work and late nights (and the rest of the team) for the x86_64. Initial results look promising with the latency test reporting figures in the 0.5 to 4 uSec range under light load. A kernel compile bumps the wost up to 9-14uSec. Firing up X,KDE, and a gamut of desktop apps really kills the numbers though - ~267uSec being the worst recorded so far, however, once X/KDE has started up, latencies are generally <30uSec. One small problem to report from the compile... With CONFIG_XENO_OPT_NUCLEUS=m, the build fails with: WARNING: "cpu_gdt_descr" [kernel/xenomai/nucleus/xeno_nucleus.ko] undefined! make[1]: *** [__modpost] Error 1 What would the preferred solution be - Export cpu_gdt_descr as it is with i386, or force xeno_nucleus to be built in ? Regards, Paul. ___ Xenomai-core mailing list Xenomai-core@gna.org https://mail.gna.org/listinfo/xenomai-core
