Subject: major race condition in ECI
From: Jesse Chappell (jesse_AT_essej.net)
Date: Tue Sep 28 2004 - 02:17:17 EEST
Hey Kai, it's been a while..... I'm sending this to the list,
but I don't think I'm added to it yet, hence the CCs.
There was a problem that plagued me years ago, and still does today, so
I dove in to debug it. Basically, using the ECI interface through
python was often causing read/sync errors in the ecasoundc_sa
subsystem when issuing the 'start' command. I turned on debugging
in ecasound_sa.c and lo and behold, found the problematic behavior:
--- cut --------
(ecasoundc_sa) writing command 'start' (cmd-counter=13).
(ecasoundc_sa) clearing list, i=(nil)
(ecasoundc_sa) found content, loglevel=2, msgsize=36.
(ecasoundc_sa) found content, loglevel=2, msgsize=36.
(ecasoundc_sa) found content, loglevel=2, msgsize=36.
(ecasoundc_sa) found content, loglevel=2, msgsize=36.
(ecasoundc_sa) gen-content validated: <<< (eca-engine) Prefi2ll5i6n g0 i-/ >>>
(ecasoundc_sa) timeout when reading return values (attempts=1)!
(ecasoundc_sa) Error='read() error', cmd='start' last_error='' cmd_cnt=13 last_cnt=12.
----- cut -------
You can see the classic multithreaded race condition when 2 threads
write to standard output, which in this case totally hoses up the ECI conversation.
Basically, the "Prefilling Buffers" stuff comes from the engine
thread while executing the start command from its queue. Meanwhile,
back in the main ecasound thread, the ctrl->print_last_value()
writes its stuff to the output at the same time.
Note that this race is most easily noticed on SMP enabled systems
(real or p4 HT).
A solution that seems to solve the problem for me is to use a
more restrictive log level mask on line 359 in ecasoundc_sa.c (257 instead of 259).
I would argue that this should be the default (only return values and errors)
for ECI conversations using libecasoundc.
Now that I've figured out this problem, I can start using ecasound
again!
jlc
This archive was generated by hypermail 2b28 : Tue Sep 28 2004 - 02:23:21 EEST