Hi,
this issue has been already discussed on the kernelnewbies mailing list
[1],[2] and suggested to be further discussed here.
I am currently working on a MPC8540-based custom board, which runs Linux
2.6.15 (arch/ppc). The original Linux sources have been modified to
support that custom board. (Additional patches to support LTT are
applied as well, though disabled in the running kernel)
I set up a periodically running kernel thread, which is delayed for a
single jiffy using schedule_timeout() in an infinite loop. It is used to
measure delays between invocations of that thread. For measuring the
distance in time the PPC's time base lower half register is used
(obtained using get_cycles() defined in asm/timex.h).
The thread calculates the delay to the previous run and only outputs the
result if a new maximum value has been determined (in respect to all
previous cycles). Further the thread outputs a warning if a very "high"
delay was determined. I.e. a delay greater than 5ms.
While running that test driver a delay of about 10ms _exactly_ occurs
every 10 minutes.
The kernel is configured using CONFIG_HZ=1000 and CONFIG_PREEMPT.
The CCB is at 333MHz, whereas the TBR update rate is 333 MHz / 8, i.e.
41,625 MHz.
Kernel configuration as a whole is found here:
http://nopaste.info/5e4d0283bb.html
And now the funny part starts.
I got a response from Bruce Rowen on kernelnewbies, telling me that he
came across the same problem. He increased his AMD-Geode-based platform
to 1GB of RAM (256MB before) and also hit the 10-minutes-issue a few
month ago (using Linux 2.6.13).
Going back to 256MB cured the problem. I did the same thing by
instructing the boot loader in order to only use 256 MB of RAM (instead
of 512MB) and yes, the 10-minutes-issue was gone as well.
Apart of some kernel threads almost all user processes have been killed
during the test. Only SSH and a bash were running (whereas a test with
network interfaces completely disabled and only operated from a serial
console turned out the same results).
The kernel comes with compiled in CIFS support, some kernel debugging
features like soft-lockup detection and preemption debugging. I.e. ps
lists the kernel threads ksoftirqd, watchdog, events, khelper, kthread,
kblockd, pdflush, aio, cifsoplockd and cifsdnotifyd.
An appropriate userspace test tool based on nanosleep() determined the
same results like the kernel thread:
root@mpc0:/# /tmp/wait.rt
looping 1 milli seconds nanosleep ...
15:26:16: #1 FRAME MAX 1996 us (at 4139773004 ticks)
15:26:16: #2 FRAME MAX 2002 us (at 4139856360 ticks)
15:26:16: #155 FRAME MAX 2102 us (at 4152597854 ticks)
15:41:37: #460398 FRAME MAX 8941 us (at 3813406605 ticks)
15:41:37: #460398 FRAME HIGH 8941 us (at 3813406605 ticks)
15:51:37: #760394 FRAME MAX 9936 us (at 3018602602 ticks)
15:51:37: #760394 FRAME HIGH 9936 us (at 3018602602 ticks)
16:01:37: #1060390 FRAME HIGH 9935 us (at 2223798809 ticks)
16:11:37: #1360386 FRAME HIGH 9934 us (at 1428994989 ticks)
16:21:37: #1660382 FRAME HIGH 9935 us (at 634191241 ticks)
[...]
Thanks for any help!
Cheers,
Florian
[1] http://thread.gmane.org/gmane.linux.kernel.kernelnewbies/23419
[2] http://thread.gmane.org/gmane.linux.kernel.kernelnewbies/23426
On Tue, 2007-11-13 at 15:24 +0100, Florian Boelstler wrote:
> Hi,
>
> this issue has been already discussed on the kernelnewbies mailing list
> [1],[2] and suggested to be further discussed here.
>
> I am currently working on a MPC8540-based custom board, which runs Linux
> 2.6.15 (arch/ppc). The original Linux sources have been modified to
> support that custom board. (Additional patches to support LTT are
> applied as well, though disabled in the running kernel)
>
> I set up a periodically running kernel thread, which is delayed for a
> single jiffy using schedule_timeout() in an infinite loop. It is used to
> measure delays between invocations of that thread. For measuring the
> distance in time the PPC's time base lower half register is used
> (obtained using get_cycles() defined in asm/timex.h).
>
> The thread calculates the delay to the previous run and only outputs the
> result if a new maximum value has been determined (in respect to all
> previous cycles). Further the thread outputs a warning if a very "high"
> delay was determined. I.e. a delay greater than 5ms.
>
> While running that test driver a delay of about 10ms _exactly_ occurs
> every 10 minutes.
>
> The kernel is configured using CONFIG_HZ=1000 and CONFIG_PREEMPT.
> The CCB is at 333MHz, whereas the TBR update rate is 333 MHz / 8, i.e.
> 41,625 MHz.
> Kernel configuration as a whole is found here:
> http://nopaste.info/5e4d0283bb.html
>
> And now the funny part starts.
> I got a response from Bruce Rowen on kernelnewbies, telling me that he
> came across the same problem. He increased his AMD-Geode-based platform
> to 1GB of RAM (256MB before) and also hit the 10-minutes-issue a few
> month ago (using Linux 2.6.13).
> Going back to 256MB cured the problem. I did the same thing by
> instructing the boot loader in order to only use 256 MB of RAM (instead
> of 512MB) and yes, the 10-minutes-issue was gone as well.
>
> Apart of some kernel threads almost all user processes have been killed
> during the test. Only SSH and a bash were running (whereas a test with
> network interfaces completely disabled and only operated from a serial
> console turned out the same results).
> The kernel comes with compiled in CIFS support, some kernel debugging
> features like soft-lockup detection and preemption debugging. I.e. ps
> lists the kernel threads ksoftirqd, watchdog, events, khelper, kthread,
> kblockd, pdflush, aio, cifsoplockd and cifsdnotifyd.
>
> An appropriate userspace test tool based on nanosleep() determined the
> same results like the kernel thread:
>
> root@mpc0:/# /tmp/wait.rt
> looping 1 milli seconds nanosleep ...
> 15:26:16: #1 FRAME MAX 1996 us (at 4139773004 ticks)
> 15:26:16: #2 FRAME MAX 2002 us (at 4139856360 ticks)
> 15:26:16: #155 FRAME MAX 2102 us (at 4152597854 ticks)
> 15:41:37: #460398 FRAME MAX 8941 us (at 3813406605 ticks)
> 15:41:37: #460398 FRAME HIGH 8941 us (at 3813406605 ticks)
> 15:51:37: #760394 FRAME MAX 9936 us (at 3018602602 ticks)
> 15:51:37: #760394 FRAME HIGH 9936 us (at 3018602602 ticks)
> 16:01:37: #1060390 FRAME HIGH 9935 us (at 2223798809 ticks)
> 16:11:37: #1360386 FRAME HIGH 9934 us (at 1428994989 ticks)
> 16:21:37: #1660382 FRAME HIGH 9935 us (at 634191241 ticks)
> [...]
You could try the latency tracer from -rt.
On 13/11/2007, Florian Boelstler <[email protected]> wrote:
> Hi,
>
> this issue has been already discussed on the kernelnewbies mailing list
> [1],[2] and suggested to be further discussed here.
>
> I am currently working on a MPC8540-based custom board, which runs Linux
> 2.6.15 (arch/ppc). The original Linux sources have been modified to
> support that custom board. (Additional patches to support LTT are
> applied as well, though disabled in the running kernel)
>
> I set up a periodically running kernel thread, which is delayed for a
> single jiffy using schedule_timeout() in an infinite loop. It is used to
> measure delays between invocations of that thread. For measuring the
> distance in time the PPC's time base lower half register is used
> (obtained using get_cycles() defined in asm/timex.h).
>
> The thread calculates the delay to the previous run and only outputs the
> result if a new maximum value has been determined (in respect to all
> previous cycles). Further the thread outputs a warning if a very "high"
> delay was determined. I.e. a delay greater than 5ms.
>
> While running that test driver a delay of about 10ms _exactly_ occurs
> every 10 minutes.
> And now the funny part starts.
> I got a response from Bruce Rowen on kernelnewbies, telling me that he
> came across the same problem. He increased his AMD-Geode-based platform
> to 1GB of RAM (256MB before) and also hit the 10-minutes-issue a few
> month ago (using Linux 2.6.13).
> Going back to 256MB cured the problem. I did the same thing by
> instructing the boot loader in order to only use 256 MB of RAM (instead
> of 512MB) and yes, the 10-minutes-issue was gone as well.
Not necessarily gone. I'd say, the question is not whether you still
have 'delays' (> 5 ms. in your case) once in a fixed interval (10
minutes) but whether you have noticeable blips, which are significant
wrt maximum 'delays' you otherwise observe between those points of
time.
What are maximum 'delays' you see before hitting this "once in 10
minutes" point?
say, with 256 Mb. the blips could just become lower (e.g. 2 ms.) and
are not reported as "big ones" (>5 ms. in your terms)...
Quite often the source of high periodic latency is SMI (System
Management Interrupts)... I don't know though, whether any of SMI
activities are somehow dependent on the size of RAM.
--
Best regards,
Dmitry Adamushko
Florian Boelstler wrote:
> While running that test driver a delay of about 10ms _exactly_ occurs
> every 10 minutes.
This is precisely the sort of thing that BIOS/firmware-level SMI handlers do,
particularly those that have monitoring or management features. Try to
determine if the kernel is doing anything during this time. If the entire
kernel seems to be frozen, talk to the people who wrote the firmware.
-- Chris
Florian Boelstler a ?crit :
> Hi,
>
> this issue has been already discussed on the kernelnewbies mailing
> list [1],[2] and suggested to be further discussed here.
>
> I am currently working on a MPC8540-based custom board, which runs Linux
> 2.6.15 (arch/ppc). The original Linux sources have been modified to
> support that custom board. (Additional patches to support LTT are
> applied as well, though disabled in the running kernel)
>
> I set up a periodically running kernel thread, which is delayed for a
> single jiffy using schedule_timeout() in an infinite loop. It is used to
> measure delays between invocations of that thread. For measuring the
> distance in time the PPC's time base lower half register is used
> (obtained using get_cycles() defined in asm/timex.h).
>
> The thread calculates the delay to the previous run and only outputs the
> result if a new maximum value has been determined (in respect to all
> previous cycles). Further the thread outputs a warning if a very "high"
> delay was determined. I.e. a delay greater than 5ms.
>
> While running that test driver a delay of about 10ms _exactly_ occurs
> every 10 minutes.
>
> The kernel is configured using CONFIG_HZ=1000 and CONFIG_PREEMPT.
> The CCB is at 333MHz, whereas the TBR update rate is 333 MHz / 8, i.e.
> 41,625 MHz.
> Kernel configuration as a whole is found here:
> http://nopaste.info/5e4d0283bb.html
>
> And now the funny part starts.
> I got a response from Bruce Rowen on kernelnewbies, telling me that he
> came across the same problem. He increased his AMD-Geode-based
> platform to 1GB of RAM (256MB before) and also hit the
> 10-minutes-issue a few month ago (using Linux 2.6.13).
> Going back to 256MB cured the problem. I did the same thing by
> instructing the boot loader in order to only use 256 MB of RAM
> (instead of 512MB) and yes, the 10-minutes-issue was gone as well.
>
> Apart of some kernel threads almost all user processes have been killed
> during the test. Only SSH and a bash were running (whereas a test with
> network interfaces completely disabled and only operated from a serial
> console turned out the same results).
> The kernel comes with compiled in CIFS support, some kernel debugging
> features like soft-lockup detection and preemption debugging. I.e. ps
> lists the kernel threads ksoftirqd, watchdog, events, khelper, kthread,
> kblockd, pdflush, aio, cifsoplockd and cifsdnotifyd.
>
> An appropriate userspace test tool based on nanosleep() determined the
> same results like the kernel thread:
>
> root@mpc0:/# /tmp/wait.rt
> looping 1 milli seconds nanosleep ...
> 15:26:16: #1 FRAME MAX 1996 us (at 4139773004 ticks)
> 15:26:16: #2 FRAME MAX 2002 us (at 4139856360 ticks)
> 15:26:16: #155 FRAME MAX 2102 us (at 4152597854 ticks)
> 15:41:37: #460398 FRAME MAX 8941 us (at 3813406605 ticks)
> 15:41:37: #460398 FRAME HIGH 8941 us (at 3813406605 ticks)
> 15:51:37: #760394 FRAME MAX 9936 us (at 3018602602 ticks)
> 15:51:37: #760394 FRAME HIGH 9936 us (at 3018602602 ticks)
> 16:01:37: #1060390 FRAME HIGH 9935 us (at 2223798809 ticks)
> 16:11:37: #1360386 FRAME HIGH 9934 us (at 1428994989 ticks)
> 16:21:37: #1660382 FRAME HIGH 9935 us (at 634191241 ticks)
> [...]
>
> Thanks for any help!
>
> Cheers,
>
> Florian
>
> [1] http://thread.gmane.org/gmane.linux.kernel.kernelnewbies/23419
> [2] http://thread.gmane.org/gmane.linux.kernel.kernelnewbies/23426
>
Hi Florian
I think you hit the periodic flush of IP route cache, which is fired
every 600 seconds per default.
(Check /proc/sys/net/ipv4/route/secret_interval )
For a 1GB machine, this hash table is so big that a full scan might take
more than 10 ms, even if empty.
Instead of using less RAM, you could just boot with rhash_entries=1024
to lower the size of this table.
Or just change secret_interval to 2000000 for example (not much more
because * HZ could overflow)
Eric
Chris Snook schrieb:
> Florian Boelstler wrote:
>> While running that test driver a delay of about 10ms _exactly_ occurs
>> every 10 minutes.
>
> This is precisely the sort of thing that BIOS/firmware-level SMI
> handlers do, particularly those that have monitoring or management
> features. Try to determine if the kernel is doing anything during this
> time. If the entire kernel seems to be frozen, talk to the people who
> wrote the firmware.
There is no such thing as BIOS on this MPC8540 embedded system.
I guess he is also using some bootloader which just gives full
control to the linux kernel.
Florian:
Check the IP route chache flushes, as Eric mentioned.
I'm working on the MPC854x as well. If you send me your scripts,
I can give them a run here to gather more information.
(I'm about to update my kernels here)
Regards,
Clemens Koller
__________________________________
R&D Imaging Devices
Anagramm GmbH
Rupert-Mayer-Stra?e 45/1
Linhof Werksgel?nde
D-81379 M?nchen
Tel.089-741518-50
Fax 089-741518-19
http://www.anagramm-technology.com
Hi Eric,
Eric Dumazet wrote:
> Instead of using less RAM, you could just boot with rhash_entries=1024
> to lower the size of this table.
I just tried that and it seems to reduce the scan time. This is the
result for the first 40 minutes of runtime:
root@mpc0:/# /tmp/wait.rt
looping 1 milli seconds nanosleep ...
17:10:11/425384 #1 MAX 1996/83117/-268599896 us/tick/usec (at 2107848557)
17:10:11/427385 #2 MAX 2001/83327/2001 us/tick/usec (at 2107931884)
17:10:11/433534 #5 MAX 2149/89477/2150 us/tick/usec (at 2108187839)
17:27:02/5897 #505291 MAX 2512/104576/2513 us/tick/usec (at 1223589469)
The first ~10ms delay usually occurred after ~15 minutes. So one could
argue that the reported HIGH-value at 17:27:02 (GMT) is the first flush
of IP route cache. And all later flushes weren't longer than 2,5ms.
Thanks to all of you, especially Eric. Now it seems I got an instrument
to lower system response time.
Cheers,
Florian
PS: Unfortunately I had to remove some CC:-entries since the local
firewall seems to not allow anything but NNTP (for gmane) and HTTP.
Hi Clemens,
Clemens Koller wrote:
> > This is precisely the sort of thing that BIOS/firmware-level SMI
> > handlers do, particularly those that have monitoring or management
> > features. Try to determine if the kernel is doing anything during this
> > time. If the entire kernel seems to be frozen, talk to the people who
> > wrote the firmware.
>
> There is no such thing as BIOS on this MPC8540 embedded system.
> I guess he is also using some bootloader which just gives full
> control to the linux kernel.
Correct, it's the U-Boot boot loader.
> Florian:
> Check the IP route chache flushes, as Eric mentioned.
> I'm working on the MPC854x as well. If you send me your scripts,
> I can give them a run here to gather more information.
> (I'm about to update my kernels here)
Thanks, the rhash_entries argument seems to have cured the problem.
Cheers,
Florian