[ag-automation] echo 1 > /sys/kernel/debug/tracing/latency_hist/enable/preemptirqsoff causes crash

Tue Nov 11 11:51:06 CET 2014

Hi Carsten, Hi everybody!

Thanks for the answer. I had already done hwlatdetect and cyclictest to
great extend. The systems seems fine. Actually I need to debug my
application, for that I hoped preemtirqsoff could help...

In case you are interested:

My application consists of an old RTAI driver which I ported to current
linux kernel. I suspect I am doing something wrong in there.
Unfortunately the documentation is sparse and the driver was ugly when I
got it. The hardware controls a RT capable bus (Profibus) and triggers
an Interrupt every 2 ms to signal that new cyclic data has arrived. I am
copying the contents of the hardware buffer to a chunk of memory
allocated in the driver and signal a waitqueue. The read/poll functions
wait_event() on the waitqueue. The real application runs in userspace.
The read() / select() shall block until new data arrives, then for now i
do some nops and write() back to the card.

This loop runs just fine for a couple of hours. Then I start to see
periodic latencies. The IRQs show latencies of +/- 20 usecs. But the
return of the read()/select() show rising latencies, which eventually
reach more than 2000 usecs. At this time, everything is then of course a
big mess and I see in
/sys/kernel/debug/tracing/latency_hist/timerandwakeup large latencies.
Funny enough they seem to come from swapper.

Both, the irq-thread and the application run at raised SCHED_FIFO
priorities (high 90s). Load of the system is ~ 0.15 on a dual core (HT
turned of).

If anyone has a hint, I would appreciate it very much.

I am trying to ftrace my problem, unfortunately it takes 4-5 hours for
the system to get into that state...

Thanks in advance!

On 11/10/2014 07:55 PM, Carsten Emde wrote:
> On 11/10/2014 06:53 PM, "Dr.-Ing. Matthias Schöpfer" wrote:
> 
>> I am having a strange latency issue with my application. But I do not
>> want to bore you with details. Funny is, I think, that:
>> echo 1 > /sys/kernel/debug/tracing/latency_hist/enable/preemptirqsoff
>> will immediately crash the machine. I have seen this with 3.12.26-rt40
>> and 3.12.31-rt45 and, I think, with 3.14.12-rt9 (I can double check, if
>> anyone is interested).
> Yes. This is known. It is not funny.
> 
>> I have another machine where it works just fine, although different
>> .config. Both are x86-Hardware, the one that crashes is x86_64.
> Same here.
> 
> Currently, we are very busy to get the development of the real-time 
> patches up and running again. Since this is priority #1 we have to 
> postpone maintenance of the preemptirqsoff crash and other known 
> problems to a later date.
> 
> In a first step of latency hunting, I would propose to run hwlatdetect 
> to exclude SMIs as the origin of the observed latency. This is the most 
> frequent single source of a latency.
> 
> If your system does not suffer from SMIs, try cyclictest with function 
> tracing instead of preemptirqsoff - this normally works pretty well. 
> When setting the break timeout, you should take in mind that function 
> tracing slows down the system by a factor of 3 to 5. Fortunately, it 
> slows down the latency too. If, for example, your system has a 
> worst-case latency of 50 µs with sporadic latencies of 200 µs, you would run
> 
>    cyclictest -m -Sp99 -i1000 -d0 -fb500
> 
> This ensures that the normal system latency will not stop cyclictest but 
> the abnormal latency will. Then locate the regular schedules of 
> cyclictest in the trace output. They will have a distance of 
> approximately 1000 µs with the exception of the last one. The culprit of 
> the latency you are searching is the code that is executed at 1000 µs 
> plus the time of the last but one cyclictest schedule.
> 
> Please come back, if this does not work for you.
> 
> Thanks,
> Carsten.
> 

-- 
Dr. Matthias Schöpfer
mz robolab GmbH
Marie-Curie-Str. 1
53359 Rheinbach

Office: +49 2226 83600 00
Fax: +49 2226 83600 11
Email: schoepfer at robolab.de

mz robolab GmbH
Vertretungsberechtigte Geschäftsführer: Dr. Rüdiger Maaß, Ralf Schulte
Registergericht Amtsgericht Bonn
Registernummer HRB 10595
---
This e-mail may contain confidential and/or privileged information. If
you are not the intended recipient (or have received this e-mail in
error) please notify the sender immediately and destroy this e-mail. Any
unauthorised copying, disclosure or distribution of the material in this
e-mail is strictly forbidden.

Diese E-Mail enthält vertrauliche und/oder rechtlich geschützte
Informationen. Wenn Sie nicht der richtige Adressat sind oder diese
E-Mail irrtümlich erhalten haben, informieren Sie bitte sofort den
Absender und vernichten Sie diese Mail. Das unerlaubte Kopieren sowie
die unbefugte Weitergabe dieser Mail ist nicht gestattet.
---
P    please consider the environment before printing this e-mail