Soft lock issue with 2.6.33.7-rt29

I have been working for weeks to get a stable rt kernel. I had been
focusing on 2.6.31.6-rt19. It is stable for about four days under stress testing before it soft locks. I am using rt19 instead of rt21, because rt19 seems to be more stable. The rtmutex issue that seems to still be in rt29 is in rt21. I also had to backport the iptables fix to rt19.

I just started looking at 2.6.33.7-rt29 again, since I can reproduce
a soft lock with it in 10-15 minutes. I have yet to get sysrq output for rt19, since it takes four days. The soft lock with rt29 as far as I can tell seems to relate to disk i/o.

There are links to two logs of rt29 from a serial console below.
They include sysrq output like "Show Blocked State" and "Show State". The level7 file is with nfsd enable, and level9 is with it disable. So nfsd doesn't seem to be the issue.

If any other debugging information is useful or needed, just say the
word.

http://proton.cygnusx-1.org/~edgan/kernel-logs/kernel-2.6.33-rt29.level7.log

http://proton.cygnusx-1.org/~edgan/kernel-logs/kernel-2.6.33-rt29.level9.log

A reproducible test-case is always the first thing we ask for :-) What is your stress test?

What policy and priority are you running your load at? Are you providing enough cycles for the system threads to run?

Darren Hart
Yocto Linux Kernel

On Wed, Nov 17, 2010 at 05:26:23PM -0800, Darren Hart wrote:

| On 11/17/2010 11:11 AM, Nathan Grennan wrote:
| >I have been working for weeks to get a stable rt kernel. I had been
| >focusing on 2.6.31.6-rt19. It is stable for about four days under stress
| >testing before it soft locks. I am using rt19 instead of rt21, because
| >rt19 seems to be more stable. The rtmutex issue that seems to still be
| >in rt29 is in rt21. I also had to backport the iptables fix to rt19.
| >
| >I just started looking at 2.6.33.7-rt29 again, since I can reproduce a
| >soft lock with it in 10-15 minutes. I have yet to get sysrq output for
| >rt19, since it takes four days. The soft lock with rt29 as far as I can
| >tell seems to relate to disk i/o.
| >
| >There are links to two logs of rt29 from a serial console below. They
| >include sysrq output like "Show Blocked State" and "Show State". The
| >level7 file is with nfsd enable, and level9 is with it disable. So nfsd
| >doesn't seem to be the issue.
| >
| >If any other debugging information is useful or needed, just say the word.
| 
| A reproducible test-case is always the first thing we ask for :-)
| What is your stress test?
| 
| What policy and priority are you running your load at? Are you
| providing enough cycles for the system threads to run?

I noticed a e1000e warning on the first log. Those are usually harmful.

You may also want to boot your kernel with

"ignore_loglevel debug initcall_debug"

appended to your kernel command line. The real issue or the important warning may happen during the boot process.

Luis

[ Luis Claudio R. Goncalves                    Bass - Gospel - RT ]
[ Fingerprint: 4FDD B8C4 3C59 34BD 8BE9  2696 7203 D980 A448 C8F8 ]

That is only in the level 7 log, and isn't in the level 9 log. So as
much as wish it wasn't there, I don't think it is the problem.

I will try these.

I have been able to boil it down the script below. If I just run yes it is fine, if I just run dd, it is fine. If you just run octave, it is fine. Run yes+dd, gets it most of the way there, but will wake up sometimes, off and on. Do all three together and it soft locks. It takes 5-15 minutes. I did it on our main example hardware, which is a server. I have also reproduced it on a desktop. Sometimes sysrq-n, to renice realtime processes, brings it out of it enough you can kill processes off.

Run with:

./stress_test

#!/bin/bash

TIMEOUT=600
MAXTEMP=75

args=getopt qt:m: $*
set -- $args

for i
do

    case "$i" in
        -q) shift; QUIET=1;;
        -t) shift; TIMEOUT=$1; shift;;
        -m) shift; MAXTEMP=$1; shift;;
    esac

done

PROCLOOP=mktemp
CHECKLOOP=mktemp

echo 1 > ${PROCLOOP}
echo 1 > ${CHECKLOOP}

trap 'cat /dev/null > $CHECKLOOP' SIGHUP SIGINT SIGTERM

if [[ ! -e which octave ]]; then
echo "Octave not installed. Please apt-get install octave." >&2 exit -1
fi

[[ $QUIET ]] || echo "Starting Octave processes..." for i in {1..8}; do
(while [ -s $PROCLOOP ]; do nice -n 20 octave --eval
"a=rand(2000);det(a);a=inv(a);"; done) > /dev/null 2>&1 & done

[[ $QUIET ]] || echo "Starting yes processes..." for i in {1..8}; do
nice -n 20 yes > /dev/null 2>&1 &
done

[[ $QUIET ]] || echo "Starting dd in 5 seconds so that other processes can finish loading..." sleep 5
for d in /dev/sd? /dev/hd?; do
if [[ -b $d ]]; then

    [[ $QUIET ]] || echo Starting dd on $d now...
    (while [ -s $PROCLOOP ]; do test -e $d && nice -n 20 dd if=$d 
of=/dev/null; sleep 10; done) > /dev/null 2>&1 &
    (while [ -s $PROCLOOP ]; do test -e $d && nice -n 20 dd if=$d 

of=/dev/null skip=20000 bs=1000000; sleep 10; done) > /dev/null 2>&1 &
fi
done

Here is a cut and paste from top right before the server soft locks.

top - 13:42:25 up 6 min, 3 users, load average: 28.52, 18.06, 7.90

Tasks: 371 total,  23 running, 348 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.3%us,  1.6%sy, 98.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:  24734280k total, 24600312k used,   133968k free, 21564200k buffers
Swap:        0k total,        0k used,        0k free,    37292k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 3440 root      39  19  5484  728  604 R  100  0.0   4:39.56 yes
 3432 root      39  19  5484  732  604 R  100  0.0   5:01.25 yes
 3436 root      39  19  5484  732  604 R  100  0.0   4:53.26 yes
 3437 root      39  19  5484  732  604 R  100  0.0   3:47.83 yes
 3441 root      39  19  5484  732  604 R  100  0.0   4:34.36 yes
 3439 root      39  19  5484  728  604 R  100  0.0   4:46.99 yes
 6030 root      39  19  243m 137m  11m R   61  0.6   0:04.96 octave
 6032 root      39  19  211m 107m  11m R   30  0.4   0:00.90 octave
 5997 root      39  19  211m 107m  11m R   19  0.4   0:00.56 octave
 6031 root      39  19  211m 107m  11m R   16  0.4   0:00.79 octave
 6029 root      39  19  211m 107m  11m R   14  0.4   0:00.66 octave
 6012 root      39  19  216m 111m  11m R   13  0.5   0:01.33 octave
 3606 root      39  19 10736 1840  704 D    4  0.0   0:05.63 dd
 3608 root      39  19  9748  856  696 D    2  0.0   0:06.61 dd
 1310 root      20   0  254m  15m 3288 S    2  0.1   0:04.95 python
  159 root      20   0     0    0    0 S    1  0.0   0:00.29 kswapd0
   61 root     -50   0     0    0    0 S    1  0.0   0:02.70 sirq-block/4
   45 root     -50   0     0    0    0 S    0  0.0   0:00.28 sirq-timer/3
   84 root     -50   0     0    0    0 S    0  0.0   0:00.56 sirq-timer/6
   97 root     -50   0     0    0    0 S    0  0.0   0:00.36 sirq-timer/7
  373 root     -51   0     0    0    0 S    0  0.0   0:01.05 irq/61-ahci
 3434 root      39  19  5484  732  604 R    0  0.0   3:53.88 yes
 3438 root      39  19  5484  732  604 R    0  0.0   1:00.93 yes
 3513 root      20   0 77060 3480 2688 S    0  0.0   0:00.09 sshd
 6007 root      39  19  243m 137m  11m R    0  0.6   0:05.06 octave
    1 root      20   0 23792 1952 1268 S    0  0.0   0:01.19 init

With the script above, the processes are actually nice 19.

Hello,

I have been working on a simulator that sends large amount of data to another system. I am having a problem where something in the system is interupting my processing loops for an extended period. I would like some suggestions on how to find the offending process and prevent it from impacting my applications while it is running.

The purpose of the simulator is to receive an instruction every 4ms and then responses by sending 400KB chunks of data on each of 8 sFPDP fibre channels to the system under test before the next instruction. The current simulator can match the 4ms frequency most of the time, but every 300 or so instructions a delay occurs of up to 15ms that impacts the system under test.

The simulator is running on an 8 core HP server running openSUSE 11.3 with real time kernel 2.6.33.1-rt11. The instruction processing thread is locked to cpu 4 and the four data sending threads are locked to cpu's 5-8.

How do you either find the offending processes or prevent other processes using the real time CPU cores? I have tried oprofile to profile the system and haven't found anything. I may not be interpreting the results correctly.

I tried the suggestions in the following website, but I may not have set it up correctly.
https://rt.wiki.kernel.org/index.php/CPU_shielding_using_/proc_and_/dev/
cpuset

Any suggestion would be helpful.

Regards
Adam Leggo

********************************************************************
This email and any attachments are confidential to the intended recipient and may also be privileged. If you are not the intended recipient please delete it from your system and notify the sender. You should not copy it or use it for any purpose nor disclose or distribute its contents to any other person.
********************************************************************

Hello Adam,

Maybe an SMI is the problem here. Did you try hwlatdetect?

Best regards
Uwe

Pengutronix e.K.                           | Uwe Kleine-König            |
Industrial Linux Solutions                 | http://www.pengutronix.de/  |
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Try ftrace, with sched_switch tracer, to see threads switching.

Jan

-----Original Message-----
From: [email protected] [mailto:[email protected]] On Behalf Of Leggo, Adam (UK)
Sent: 19. listopadu 2010 13:05
To: [email protected]
Subject: Locating processes impacting my rt application

Hello,

I have been working on a simulator that sends large amount of data to another system. I am having a problem where something in the system is interupting my processing loops for an extended period. I would like some suggestions on how to find the offending process and prevent it from impacting my applications while it is running.

The purpose of the simulator is to receive an instruction every 4ms and then responses by sending 400KB chunks of data on each of 8 sFPDP fibre channels to the system under test before the next instruction. The current simulator can match the 4ms frequency most of the time, but every 300 or so instructions a delay occurs of up to 15ms that impacts the system under test.

The simulator is running on an 8 core HP server running openSUSE 11.3 with real time kernel 2.6.33.1-rt11. The instruction processing thread is locked to cpu 4 and the four data sending threads are locked to cpu's 5-8.

How do you either find the offending processes or prevent other processes using the real time CPU cores? I have tried oprofile to profile the system and haven't found anything. I may not be interpreting the results correctly.

I tried the suggestions in the following website, but I may not have set it up correctly.
https://rt.wiki.kernel.org/index.php/CPU_shielding_using_/proc_and_/dev/
cpuset

Any suggestion would be helpful.

Regards
Adam Leggo

********************************************************************
This email and any attachments are confidential to the intended recipient and may also be privileged. If you are not the intended recipient please delete it from your system and notify the sender. You should not copy it or use it for any purpose nor disclose or distribute its contents to any other person.
********************************************************************

--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Interesting, so you're locking up a preempt-rt kernel with SCHED_OTHER tasks running at the least favorable priority.

Note: nice -n 19 is actually the valid nice value (20 and higher seem to be accepted, but have the same effect as 19). NICE(1)

How many CPUs on your test machine?

Darren Hart
Yocto Linux Kernel

The server is dual quad-core. The desktop is a quad-core with hyperthreading. Both are i7 based.