Back Midas Rome Roody Rootana
  Midas DAQ System, Page 35 of 137  Not logged in ELOG logo
New entries since:Wed Dec 31 16:00:00 1969
ID Date Authorup Topic Subject
  569   07 May 2009 Konstantin OlchanskiInfomidas misc timeout fixes
(catching up on recent changes from t2k and pienu)

Various timeout problems fixed:
- cm_transition() timeouts now settable from ODB (/experiment/transition timeout, transition connect 
timeout). Rev 4479
- rpc_client_call() timeout did not work because of bad select() and alarm() interaction. Rev 4479
- implement rpc connect timeout (was hardwired 10 sec) via rpc_{set,get}_option(-2, RPC_OTIMEOUT). Rev 
4478
- ss_mutex_wait_for() timeout only worked if 1Hz alarm() interrupts are present. Now I use semtimedop() 
and timeout should always work. Rev 4472

K.O.
  570   07 May 2009 Konstantin OlchanskiInfoRPC.SHM gyration
When using remote midas clients with mserver, you may have noticed the zero-size .RPC.SHM files 
these clients create in the directory where you run them. These files are associated with the semaphore 
created by the midas rpc layer (rpc_call) to synchronize rpc calls between multiple threads. This 
semaphore is always created, even for single-threaded midas applications. Also normally midas 
semaphore files are created in the midas experiment directory specified in exptab (same place as 
.ODB.SHM), but for remote clients, we do not know that location until we start making rpc calls, so the 
semaphore file is created in the current directory (and it is on a remote machine anyway, so this 
location may not be visible locally).

There are 2 problems with these semaphores:
1) in multiple experiments, we have observed the RPC.SHM semaphore stuck in a locked state, 
requiring manual cleanup (ipcrm -s xxx). So far, I have failed to duplicate this lockup using test 
programs and test experiments. The code appears to be coded correctly to automatically unlock the 
semaphore when the program exits or is killed.
2) RPC.SHM is created as a global shared semaphore so it synchronizes rpc calls not just for all threads 
inside one application, but across all threads in all applications (excessive locking - separate 
applications are connected to separate mservers and do not need this locking); but only for applications 
that run from the same current directory - RPC.SHM files in different directories are "connected" to 
different semaphores.

To try to fix this, I implemented "private semaphores" in system.c and made rpc_call() use them.

This introduced a major bug - a semaphore leak - quickly using up all sysv semaphores (see sysctl 
kernel.sem).

The code was now reverted back to using RPC.SHM as described above.

The "bad" svn revisions start with rev 4472, the problem is fixed in rev 4480.

If you use remote midas clients and have one of these bad revisions, either update midas.c to rev 4480 
or apply this patch to midas.c::rpc_call():
ss_mutex_create("", &_mutex_rpc);
should read
ss_mutex_create("RPC", &_mutex_rpc);

Apologies for any inconvenience caused by this problem
K.O.
  571   07 May 2009 Konstantin OlchanskiInfomhttpd now uses mtransition
mhttpd function for starting and stopping runs now uses cm_transition(DETACH) which spawns an 
external helper program called mtransition to handle the transition sequencing. This helps with the old 
problem of looking at a blank screen for a long time if some frontends take a long time to process run 
transitions. Now mhttpd returns right back and shows start "starting run", "stopping run", etc as 
appropriate.

svn rev 4484 (some bits of this feature are present in rev 4473 and later).
K.O.

P.S. In one of our experiments, I sometimes see mhttpd getting "stuck" when starting or stopping a run 
using this feature. strace shows it is stuck in repeated calls to wait(), but I am unable to reproduce this 
problem in a test system and it happens only sometimes in the experiment. When it does, mhttpd has to 
be restarted. Replacing system("mtransition ...") with ss_sysem("mtransition ...") seems to fix this problem, 
but there are downsides to this (mtransition debug output vanishes) so I am not committing this yet.
K.O.
  572   07 May 2009 Konstantin OlchanskiBug Fixmhttpd "Names" length
mhttpd did not like it when the equipment "Names" arrays had different length compared to the 
corresponding "Variables" arrays. These limitations are now removed.
svn rev 4469
K.O.
  573   07 May 2009 Konstantin OlchanskiBug FixFixed mlogger run start and stop
Fixed problems with mlogger starting and stopping runs.

Basic difficulty was with the mlogger using ASYNC transitions, which did not implement proper 
transition sequencing according to transition sequence numbers. Basically all clients were called at the 
same time, regardless of how long they took to process the transitions.

Switching from ASYNC to SYNC transitions introduces a deadlock between mlogger (not reading data 
from SYSTEM buffer while inside cm_transition) and any program trying to write into the SYSTEM buffer 
(buffer is full, does not listen for transition requests while waiting for mlogger which tries to call it's 
transition handler).

Then we invented the mtransition helper program. In the original implemtation for t2k it was spawned 
directly from the mlogger to stop the run (avoiding the deadlock). Then cm_transition(DETACHED) was 
introduced, but the mlogger start/stop/restart run logic became broken. One problem was with when 
auto restart delay is zero, mtransition tries to restart the run before previous run is stopped (instead, 
mlogger should restart the run from it's tr_stop() handler). Another problem was with the auto restart 
delay counting from the time when we start stopping the run - because stopping the run can take an 
unpredictable time, depending on when various frontends have to do - it is impossible to have a 
predictable delay between runs (again this is fixed by restarting the run from mlogger.c::tr_stop()).

All this has been straightened out by svn revision 4484. Basically the old run stop/restart logic was 
restored in mlogger.c, using cm_transition(DETACH) to avoid the deadlocks.

To remind all, these are the present controls for transitions initiated by mlogger:

/experiment/transition debug flag - set to "2" to capture transition sequences into midas.log
/experiment/transition timeout and transition connect timeout - one can change default timeouts as 
needed to accommodate non cooperative frontends.
/logger/async transitions - do not use mtransition - do ASYNC transitions, as before.
/logger/auto restart delay - delay between stopping the run (mlogger.c::tr_stop) and starting the next 
run.

svn rev 4484
K.O.
  574   07 May 2009 Konstantin OlchanskiInfoSQL history documentation
Documentation for writing midas history data to SQL (mysql) is now documented in midas doxygen files 
(make dox; firefox doxfiles/html/index.html). The corresponding logger and mhttpd code has been 
committed for some time now and it is used in production environment by the t2k/nd280 slow controls 
daq system at TRIUMF.

svn rev 4487
K.O.
  575   07 May 2009 Konstantin OlchanskiBug Reportodbedit bad ctrl-C
When using "/bin/bash" shell, if I exit odbedit (and other midas programs) using ctrl-C, the terminal 
enters a funny state, "echo" is turned off (I cannot see what I type), "delete" key does not work (echoes 
^H instead).

This problem does not happen if I exit using the "exit" command or if I use the "/bin/tcsh" shell.

When this happens, the terminal can be restored to close to normal state using "stty sane", and "stty 
erase ^H".

The terminal is set into this funny state by system.c::getchar() and normal settings are never restored 
unless the midas program calls getchar(1) at the end. If the program does not finish normally, original 
terminal settings are never restored and the terminal is left in a funny state.

It is not clear why the problem does not happen with /bin/tcsh - perhaps they restore sane terminal 
settings automatically for us.
K.O.
  576   07 May 2009 Konstantin OlchanskiBug Reportmlogger duplicate event problem
We have seen on several daq systems this problem: we start a run and observe that the number of 
events written by mlogger to the output file is double the number of events actually collected. Upon 
inspection of the output file, we see that every event is written twice. Restarting the run usually fixes 
this problem.

We now traced this to an error in mlogger.c. If we start a run and the run transition fails in some 
frontend,  mlogger does not disconnect from the SYSTEM buffer (it does not know the transition failed 
and the run did not really start). The SYSTEM buffer connection and the associated event request 
remain active. Then we start the next run and mlogger connects to the SYSTEM buffer again, creates a 
second (third, etc) event request. Eventually mlogger reaches the maximum permitted number of event 
requests and no more runs can be started unless mlogger is restarted.

If at some point a run actually starts successfully, there are multiple event requests present from 
mlogger and theoretically, each event should be written to the output file many times. This was a 
puzzle until we got a good laugh from looking at mlogger.c::receive_event() callback - in retrospect it 
is obvious why events are only written in duplicate.

Then, after the run is ended, mlogger disconnects from the SYSTEM buffer, all multiple event requests 
are automatically deleted and the problem is not present during the next run.

I am not yet sure how to best fix this, but I see that other midas programs (i.e. mevb) suffer form the 
same problem - multiple connections to the event buffer - in presence of failed run starts. I think we 
have seen "event duplication" from mevb, as well.

K.O.
  577   15 May 2009 Konstantin OlchanskiInfomidas misc timeout fixes
> - cm_transition() timeouts now settable from ODB (/experiment/transition timeout, transition connect timeout). Rev 4479

transition connect timeout was actually only half of that specified because of an error in computing timeout arguments to the select() system 
call in recv_string() in system.c. This is now fixed.

rev 4488
K.O.
  578   15 May 2009 Konstantin OlchanskiInfomidas misc timeout fixes
> - cm_transition() timeouts now settable from ODB (/experiment/transition timeout, transition connect timeout). Rev 4479

transition connect timeout was actually only half of that specified because of an error in computing timeout arguments to the select() system 
call in recv_string() in system.c. This is now fixed.

rev 4488
K.O.
  581   19 May 2009 Konstantin OlchanskiSuggestionQuestion about using mvmestd.h
> The problem is: I renamed my SIS1100 devices as /dev/sis1100/xxxxx. So I have to hack the 
"sis3100.c".

As in the old joke, "Doctor, it hurts when I do *this*; Doctor answers: then don't do it!"

But I am curious why you want to change the "manufacturer-default" device names. For the vmivme.c and 
gefvme.c drivers that we use at TRIUMF, there is no obvious reason or gain from changing device names.

K.O.
  583   21 May 2009 Konstantin OlchanskiInfomhttpd now uses mtransition
> mhttpd function for starting and stopping runs now uses cm_transition(DETACH) which spawns an 
> external helper program called mtransition to handle the transition sequencing.
> 
> P.S. In one of our experiments, I sometimes see mhttpd getting "stuck" when starting or stopping a run 
> using this feature. strace shows it is stuck in repeated calls to wait(), but I am unable to reproduce this 
> problem in a test system and it happens only sometimes in the experiment. When it does, mhttpd has to 
> be restarted. Replacing system("mtransition ...") with ss_sysem("mtransition ...") seems to fix this problem, 
> but there are downsides to this (mtransition debug output vanishes) so I am not committing this yet.
> K.O.

Found the problem. As observed on SL5 systems, the GLIBC "system()" function breaks if the user application
installs a SIGCHLD handler that "steals" wait() notifications. Such a handler is installed by the MIDAS ss_exec()
function in system.c.

I would count this as a GLIBC bug - their "system()" function should survive in the presence of non-default signal
handlers installed by the user, and in fact my copy of "man signal" talks about the "system()" doing something
special about SIGCHLD. Obviously whatever they do is broken, at least in the SL5 GLIBC.

I am now testing an implementation using MIDAS ss_spawnvp().

The simplest way to reproduce the problem: start mhttpd; start/stop runs - mtransition works perfectly; start some
program from the MIDAS "programs" page (this calls "ss_exec()"), try to start a run - mhttpd will hang inside the
system() GLIBC function, every time. mhttpd has to be killed with "kill -KILL" to recover.

K.O.
  584   02 Jun 2009 Konstantin OlchanskiInfomhttpd now uses mtransition
> > mhttpd function for starting and stopping runs now uses cm_transition(DETACH) which spawns an 
> > external helper program called mtransition to handle the transition sequencing.
>
> ... the GLIBC "system()" function breaks if the user application
> installs a SIGCHLD handler that "steals" wait() notifications. Such a handler is installed by the MIDAS ss_exec()
> function in system.c.
>
> I am now testing an implementation using MIDAS ss_spawnvp().

cm_transition() starting mtransition helper using ss_spawnvp() committed svn rev 4495.

K.O.
  585   02 Jun 2009 Konstantin OlchanskiBug Reportmlogger duplicate event problem
> We have seen on several daq systems this problem: we start a run and observe that the number of 
> events written by mlogger to the output file is double the number of events actually collected. Upon 
> inspection of the output file, we see that every event is written twice. Restarting the run usually fixes 
> this problem.

mlogger.c fixed svn rev 4497. (from tr_start(), call tr_stop() if somehow it was not called already by end-run transition).

K.O.
  586   02 Jun 2009 Konstantin OlchanskiInfoRPC.SHM gyration
> When using remote midas clients with mserver, you may have noticed the zero-size .RPC.SHM files 
> these clients create in the directory where you run them. These files are associated with the semaphore 
> created by the midas rpc layer (rpc_call) to synchronize rpc calls between multiple threads. This 
> semaphore is always created, even for single-threaded midas applications. Also normally midas 
> semaphore files are created in the midas experiment directory specified in exptab (same place as 
> .ODB.SHM), but for remote clients, we do not know that location until we start making rpc calls, so the 
> semaphore file is created in the current directory (and it is on a remote machine anyway, so this 
> location may not be visible locally).
> 
> There are 2 problems with these semaphores:

A 3rd problem surfaced - on SL5 Linux, the global limit is 128 or so semaphores and on at least one heavily used machine that hosts multiple 
experiments we simply run out of semaphores.

For "normal" semaphores, their number is fixed to about 5 per experiment (one for each shared memory buffer), but the number of RPC 
semaphores is not bounded by the number of experiments or even by the number of user accounts - they are created (and never deleted) for 
each experiment, for each user that connects to each experiment, for each subdirectory where the each user happened to try to start a 
program that connects to the each experiment. (to reuse the old children's rhyme).

Right now, MIDAS does not have an abstraction for "local multi-thread mutex" (i.e. pthread_mutex & co) and mostly uses global semaphores 
for this task (with interesting coding results, i.e. for multithreaded locking of ODB). Perhaps such an abstraction should be introduced?

K.O.
  587   03 Jun 2009 Konstantin OlchanskiBug FixFix db_open_record() error return
The odb hot-link function db_open_record() did not return an error when the system limit for hotlinks is 
exceeded and no more hot links could be added (silent failure). This is now fixed.
odb.c svn rev 4500
K.O.
  593   05 Jun 2009 Konstantin OlchanskiBug Reportmhttpd command line experiment specifying
> I guess you have to do some debugging there. Note that "detached" transitions have 
> been implemented recently by Konstantin, so maybe your problem is related to that. 
> In this case Konstantin should check what's wrong.

Yes, I think there is a problem - cm_transition() starts the mtransition helper without the "-h expt" switch, so 
mtransition can only connect to the "default" experiment. Will fix. K.O.
  595   16 Jun 2009 Konstantin OlchanskiBug Reportmlogger duplicate event problem
> > We have seen on several daq systems this problem: we start a run and observe that the number of 
> > events written by mlogger to the output file is double the number of events actually collected. Upon 
> > inspection of the output file, we see that every event is written twice. Restarting the run usually fixes 
> > this problem.
> 
> mlogger.c fixed svn rev 4497. (from tr_start(), call tr_stop() if somehow it was not called already by end-run transition).

There is a new problem: after an unsuccessful run start, the next run start bombs with the error "output file runNNN.mid already exists". One way around this is to 
manually remove the useless data file, another is to bump up the run number. Better solution is to automatically erase the output file created by unsuccessful run 
starts.

K.O.
  596   18 Jun 2009 Konstantin OlchanskiBug Reportmhttpd command line experiment specifying
> > I guess you have to do some debugging there. Note that "detached" transitions have 
> > been implemented recently by Konstantin, so maybe your problem is related to that. 
> > In this case Konstantin should check what's wrong.
> 
> Yes, I think there is a problem - cm_transition() starts the mtransition helper without the "-h expt" switch, so 
> mtransition can only connect to the "default" experiment. Will fix. K.O.

Fixed midas.c svn rev 4506: in cm_transition(), always pass "-e expt" to mtransition, if connected remotely, pass the
"-h host:port".

svn rev 4506
K.O.
  597   24 Jun 2009 Konstantin OlchanskiBug ReportTR_STARTABORT transition, mlogger duplicate event problem
> > > We have seen on several daq systems this problem: we start a run and observe that the number of 
> > > events written by mlogger to the output file is double the number of events actually collected. Upon 
> > > inspection of the output file, we see that every event is written twice. Restarting the run usually fixes 
> > > this problem.
> > 
> > mlogger.c fixed svn rev 4497. (from tr_start(), call tr_stop() if somehow it was not called already by end-run transition).
> 
> There is a new problem: after an unsuccessful run start, the next run start bombs with the error "output file runNNN.mid already exists". One way around this is to 
> manually remove the useless data file, another is to bump up the run number. Better solution is to automatically erase the output file created by unsuccessful run 
> starts.

Stefan suggested implementing a new transition, TR_STARTABORT, issued if TR_START fails. mlogger can use it to cleanup open files, etc, similar to TR_STOP.

This is now implemented. In mlogger, TR_STARTABORT is similar to TR_STOP, but deletes open output files and does not save end-of-run information into databases, etc. mfe.c does not handle this trnasition yet, but I 
plan to add it - to fix the observed situations where the run failed to start, but some equipment does not know about it and continues to generate events and send data.

svn rev 4514
K.O.
ELOG V3.1.4-2e1708b5