[Jackit-devel] Re: [linux-audio-dev] 2.4.20 + lowlat +preempt + alsa + jack = dead computer

Fernando Pablo Lopez-Lezcano nando at ccrma.Stanford.EDU
Wed Jan 8 20:48:00 UTC 2003


> > this will produce reams of output, but will provide you with the next
> > hint. 
> 
> reams of output collected...
> 
> > problem: the output will affect scheduling, which might make the
> > problem go away. i recommend outputting it to a file if possible, and
> > viewing after the fact.
> 
> I have big files for jack and ardour, and the problem did not go away. I
> have pored over the huge files but I don't seem to find anything that
> looks like a glitch. Will keep looking...

I have some data but I have no idea if it is significant. This is
running rt_monitor as a safeguard, jack and finally ardour. To speed up
the death of the patient (in my experience) a tar cvf usr.tar /usr was
also run in a separate terminal...

I looked for time transients in the cycle count of the listings. This is
the tail of it for ardour (abs cycles followed by delta cycles):

25316620570960 151478724
25314593862618 170551720
25316905845228 174448260
25283295747490 1690268954

So the last delta time is much bigger, a good candidate. Finding the time 
in the listing gives me this:

jack:27813:25281569457264 client.c:jack_client_thread:556: client polling on event_fd and graph_wait_fd...
jack:27813:25281605113512 client.c:jack_client_thread:664: client 27813 signalled at 25281605055172, awake for process at 25281605109372 (delay = 32.071006 usecs) (wakeup on graph_wait_fd==30)
jack:27813:25281605240108 client.c:jack_client_thread:686: client finished processing at 25281605238028 (elapsed = 76.127811 usecs), writing on graph_next_fd==31
jack:27813:25281605450304 client.c:jack_client_thread:694: client sent message to next stage by 25281605450388, client reading on graph_wait_fd==30
jack:27813:25281605461784 client.c:jack_client_thread:699: reading cleanup byte from pipe
jack:27813:25281605472500 client.c:jack_client_thread:710: process cycle fully complete
jack:27813:25281605478536 client.c:jack_client_thread:556: client polling on event_fd and graph_wait_fd...

GLITCH! (this is not part of the listing :-)

jack:27813:25283295747490 client.c:jack_client_thread:556: client polling on event_fd and graph_wait_fd...
jack:27813:25283359653444 client.c:jack_client_thread:664: client 27813 signalled at 25281641118776, awake for process at 25283359647196 (delay = 1016880.700592 usecs) (wakeup on graph_wait_fd==30)
jack:27813:25283359829424 client.c:jack_client_thread:686: client finished processing at 25283359827480 (elapsed = 106.676923 usecs), writing on graph_next_fd==31
jack:27813:25283360445692 client.c:jack_client_thread:694: client sent message to next stage by 25283360445776, client reading on graph_wait_fd==30
jack:27813:25283360457440 client.c:jack_client_thread:699: reading cleanup byte from pipe
jack:27813:25283360468308 client.c:jack_client_thread:710: process cycle fully complete

So there are two "client polling" in a row with nothing in between...

The second one presumably happens when rt_monitor downgrades the process to
SCHED_OTHER? Or maybe that is what is "hanging"? 

In the jack side of things:

25317681129070 143623260
25316620498912 151380488
25314593789218 170399340
25283359590208 1718469688

jack:27772:25281605266960 engine.c:jack_process:584: reading byte from subgraph_wait_fd==13
jack:27772:25281641074368 engine.c:jack_process:465: considering client alsa_pcm for processing
jack:27772:25281641107540 engine.c:jack_process:498: in-process client has no process() function
jack:27772:25281641114096 engine.c:jack_process:465: considering client ardour for processing
jack:27772:25281641120520 engine.c:jack_process:516: 

**** alsa_pcm: xrun of at least 996.047 msecs

calling process() on an OOP subgraph, fd==7

GLITCH!

jack:27772:25283359590208 engine.c:jack_process:535: waiting on fd==13 for process() subgraph to finish
jack:27772:25283359952396 engine.c:jack_process:584: reading byte from subgraph_wait_fd==13
jack:27772:25283396656700 engine.c:jack_process:465: considering client alsa_pcm for processing
jack:27772:25283396688968 engine.c:jack_process:498: in-process client has no process() function
jack:27772:25283396695880 engine.c:jack_process:465: considering client ardour for processing

I did another test with the sleep in rt_monitor changed from 2 seconds
to 10 seconds (to keep the machine catatonic for a longer time) and the
result was not as interesting because jack timed out when it recovered
and killed itself and ardour. 

In that test I found three back to back polls with big timeouts in
between and two more somewhere else in the file. 

-- Fernando





More information about the Linux-audio-dev mailing list