> As of svn rev 4794, midas builds, runs and should be fully usable on MacOS 10.6.4. Previous revisions did 
> not compile due to assorted Linuxisms and did not run because of a sizeof() problem in ss_gettid(). Also 
> one of the system header files (mtio.h?) present in MacOS 10.5 vanished from 10.6.

It turns out that on MacOS 10.6 the default maximum SYSV shared memory size is about 2 Mbytes, too small even for the default MIDAS SYSTEM 
event buffer.

Svn revision 4807 implements POSIX shared memory, which does not seem to have such a small size limit and makes it the default on MacOS.

This update fixes the last issue that I am aware of for running MIDAS on MacOS.

svn rev 4807
K.O.

mhttpd.c svn rev 4823 implements a modified history planel editor. all previous functions should work 
as before (minus new bugs).

New experimental functions added:

a) there is a new column "Order" containing numbers 10, 20, 30, etc. If you change "30" to (say) "15" 
and press "refresh", the history variables will be reordered according to the new values. If you change 
(say) "10" to "" (empty) or "0" and press "refresh", this variable will be deleted. (But there is a UI wart - if 
you accidentally change the order value to something non-numeric (i.e. "aaa1" or " 1" (leading space) 
and press "enter", the variable will be immediately deleted from odb - "enter" works as "refresh + save" 
- should probably work as "refresh" requiring explicit press on the "save" button).

b) there is a new button "List all" to list all existing variables - next to each variable is a checkbox - 
select any checkboxes and press "add selected" to add selected variables to the history plot. You may 
find this function useful (or not), depending on how many variables you have in your history. For 
T2K/ND280 this is still not good enough (there are still too many variables) and I want to change this to 
a 3 level (equipment, history event, history tag) expandable/collapsable tree (or whatever is simplest to 
implement) - to permit the user to quickly zoom on the interesting variables.

I may still tweak with the UI of these new functions, but the basic functionality (reorder+delete and 
selection of multiple variables from a list) seems to be solid. Comments and suggestions on how to 
make it work the best for your experiment are very welcome.

K.O.

> mhttpd.c svn rev 4823 implements a modified history planel editor. all previous functions should work 
> as before (minus new bugs). New experimental functions added:
> 
> a) there is a new column "Order" containing numbers 10, 20, 30, etc. ...

While this seems to work well enough, it might remain a function for "advanced users". For novice
users, a simpler gui, i.e. with "move up" and "move down" buttons, would have been "better", or
at least more familiar. (However I have double plus negative experience using nice
looking "move up and down buttons" to rearrange something I actually need to rearrange,
so I have no interest in implementing something I do not want to use. Think about moving
an item all the way from the bottom of a 10 item list to the very top. No do this not as a mental
exercise, but on a slow loading mhttpd web page running somewhere in Japan).

> b) there is a new button "List all variables" to list all existing variables

Some improvement here (mhttpd.c svn 4823): variables are organized by equipment and by history event
into an expandable list. (I already know that this list expansion does not play well with web page
scrolling, same problem exists in the ODB inline editor).

Again, midas users who have a small number of history events may find this new function
not so useful, but the old way was pretty much unusable for T2K/ND280.

Also, for users with a large number of history events, there 2 new ODB variables
/History/MaxDisplayEvents and /History/MaxDisplayTags which limit the maximum
number of events and tags listed in the old scrollable "option" selector history editor.
For the T2K/ND280 case, this reduces the size of the web page and reduces the page load
time quite substantially. (I picked default values of 20 events and 200 tags quite arbitrary,
perhaps the default should have been "no limit", but then nobody would benefit from this
possibility to substantially reduce web page load times - unless they read documentation (yea, right!)
that is not yet written).

K.O.

In svn rev 4825, I added host based access control to mserver (the MIDAS RPC server). The implementation 
is a verbatim copy mhttpd host based access control list (-a command line switch).

Same as for mhttpd, "mserver -a hostname" enables access control and only permits access from listed 
host names (supply multiple -a switches for multiple hostnames).

This access control does not apply yet for the MIDAS RPC socket connections between MIDAS clients used 
to do RPC callbacks, i.e. to request run transitions. Each MIDAS program is listening for MIDAS RPC 
connections on a high TCP port and at present accepts connections from anybody. To implement access 
controls one could add "-a" switches to every midas application (lot of work) or fill the access control list 
automatically from ODB. mserver still has to use the "-a" command line switches because there is no ODB 
connection when it has to accept or reject remote sockets.

svn rev 4825
K.O.

Prior to odb.c rev 4829 and mhttpd.c rev 4830 committed a few minutes ago, HTML javascript 
ODBGet("/non_existant_odb_entry") caused ODB corruption requiring ODB reload from backup file.

It turns out that ODBGet() tries to create ODB entries if they do not already exist, but because ODBGet() was 
called without the "type", "length", etc arguments, the mhttpd "jset" command was issued with "type" set to 
zero. This resulted in a db_create_key() call with "type" set to zero which created an invalid ODB entry. 
odb.c rev 4829 adds a check for "type<=0" (check for "type>=TID_LAST" was already there).

In addition, mhttpd.c rev 4830 adds a "jset" check for type==0.
K.O.

We had javascript ODBGet() and ODBSet() functions for some time now, permitting implementation of 
"page-reload-free" "self-updating" web pages. I finally got around to put all the javascript bits together 
to actually implement such a page. The main difference from a normal MIDAS "custom" page is the data 
update method - instead of fully reloading the page (via "<meta http-equiv="Refresh" content="60">" 
or javascript location.reload()) - I use ODBGet() to read new data from ODB and HTML DOM access to 
update it on the web page. Note that this is not quite AJAX because the load() function is synchronous 
and (i.e. on the MacOS 10.6 Safari web browser) completely freezes the web browser during data update 
(but no freeze on the Linux Firefox, go figure). An asynchronous ODBGet() should be easy to implement, 
but I can see how a fully asynchronous load() function would lose some of the simplicity of this 
example. (I hope elog does not mangle my example too much).
K.O.

<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
  <head>
    <title>PostAmp control</title>
  </head>

  <body>
    <h1>PostAmp control</h1>

    <script src='mhttpd.js'></script>
    <script type="text/javascript">

var numcrates = 2;
var numpachan;
var reloadTimerId = 0;

function load()
{
  document.getElementById('LastUpdated').innerHTML = "Reloading..." + new Date;

  var crates_table = document.getElementById('crates');
  var slots_table = document.getElementById('cards');

  var Csn = ODBGet('/Equipment/PostAmp/Settings/PACtrlSerialNo[*]');
  for (var i = 0; i < numcrates; i++)
    crates_table.rows[1+i].cells[1].innerHTML = Csn[i];

  var MaxTemp = ODBGet('/Equipment/PostAmp/Variables/MaxTemp[*]');
  for (var i = 0; i < numcrates; i++)
    crates_table.rows[1+i].cells[2].innerHTML = MaxTemp[i];

  var D_TP = ODBGet('/Equipment/PostAmp/Variables/D_TP[*]');
  var M_TP = ODBGet('/Equipment/PostAmp/Variables/M_TP[*]');

  for (var i = 0; i < numcrates; i++)
    crates_table.rows[1+i].cells[3].innerHTML = D_TP[i] + " / " + M_TP[i];

  var sn = ODBGet('/Equipment/PostAmp/Settings/PASerialNo[*]');
  for (var i = 0; i < numpachan; i++)
    slots_table.rows[1+i].cells[1].innerHTML = sn[i];

  var VoltageP  = ODBGet('/Equipment/PostAmp/Variables/VoltageP[*]');
  for (var i = 0; i < numpachan; i++)
    slots_table.rows[1+i].cells[2].innerHTML = VoltageP[i];

  var VoltageM  = ODBGet('/Equipment/PostAmp/Variables/VoltageM[*]');
  for (var i = 0; i < numpachan; i++)
    slots_table.rows[1+i].cells[3].innerHTML = VoltageM[i];

  var Temp      = ODBGet('/Equipment/PostAmp/Variables/Temp[*]');
  for (var i = 0; i < numpachan; i++)
    slots_table.rows[1+i].cells[4].innerHTML = Temp[i];

  var D_VTp     = ODBGet('/Equipment/PostAmp/Variables/D_VTp[*]');
  var M_VTp     = ODBGet('/Equipment/PostAmp/Variables/M_VTp[*]');

  for (var i = 0; i < numpachan; i++)
    slots_table.rows[1+i].cells[5].innerHTML = D_VTp[i] + " / " + M_VTp[i];

  var D_Thresh  = ODBGet('/Equipment/PostAmp/Variables/D_Thresh[*]');
  var M_ThreshA = ODBGet('/Equipment/PostAmp/Variables/M_ThreshA[*]');
  var M_ThreshB = ODBGet('/Equipment/PostAmp/Variables/M_ThreshB[*]');

  for (var i = 0; i < numpachan; i++)
    slots_table.rows[1+i].cells[6].innerHTML = D_Thresh[i] + " / " + M_ThreshA[i] + " / " + M_ThreshB[i];

  document.getElementById('LastUpdated').innerHTML = "Last updated: " + new Date;
}

function reload()
{
  clearTimeout(reloadTimerId);
  load();
  reloadTimerId = setTimeout('reload()', 10000);
}

function main()
{
  clearTimeout(reloadTimerId);

  document.writeln("<p id=LastUpdated>Last updated: </p>");

  document.writeln("<input type=button value='Reload' onClick='reload();'></input>");
  document.writeln("<input type=button value='TP enable' onClick='clearTimeout(reloadTimerId); 
ODBSet(\"/Equipment/PostAmp/Settings/Command\", \"gtp 1\"); reload();'></input>");
  document.writeln("<input type=button value='TP disable' onClick='clearTimeout(reloadTimerId); 
ODBSet(\"/Equipment/PostAmp/Settings/Command\", \"gtp 0\"); reload();'></input>");
  //document.writeln("<input type=button value='Thresh 100' onClick='clearTimeout(reloadTimerId); 
ODBSet(\"/Equipment/PostAmp/Settings/Command\", \"gvth 100\"); reload();'></input>");
  //document.writeln("<input type=button value='Vtest 200' onClick='clearTimeout(reloadTimerId); 
ODBSet(\"/Equipment/PostAmp/Settings/Command\", \"gvtest 200\"); reload();'></input>");

  document.writeln("Set VTp: ");
  document.writeln("<input type=input size=5 value='200' onKeyPress='if (event.keyCode==13) { 
clearTimeout(reloadTimerId); ODBSet(\"/Equipment/PostAmp/Settings/Command\", \"gvtest \" + 
this.value); reload(); }'></input>");

  document.writeln("Set Thresh: ");
  document.writeln("<input type=input size=5 value='100' onKeyPress='if (event.keyCode==13) { 
clearTimeout(reloadTimerId); ODBSet(\"/Equipment/PostAmp/Settings/Command\", \"gvth \" + 
this.value); reload(); }'></input>");

  document.write("<table id=crates border=1>");
  
  document.writeln("<tr align=center>");
  document.writeln("<th>Crate");
  document.writeln("<th>SerialNo");
  document.writeln("<th>MaxTemp");
  document.writeln("<th>D_TP / M_TP");
  document.writeln("</tr>");
  

  for (c = 0; c < numcrates; c++) {
    document.writeln("<tr align=center>");
    document.writeln("<td>" + c);
    document.writeln("<td>sn");
    document.writeln("<td>maxtemp");
    document.writeln("<td>d_tp/m_tp");
    document.writeln("</tr>");
  }
  document.writeln("</table>");
  
  document.write("<table id=cards border=1>");
  
  document.writeln("<tr align=center>");
  document.writeln("<th>Crate/Slot");
  document.writeln("<th>SerialNo");
  document.writeln("<th>V+5");
  document.writeln("<th>V-5");
  document.writeln("<th>Temp");
  document.writeln("<th>VTp");
  document.writeln("<th>Thresh");
  document.writeln("</tr>");
  
  for (c = 0; c < numcrates; c++) {
    for (s = 1; s <= 24; s++) {
      xchan = (c*24) + (s-1);
      document.writeln("<tr align=center>");
      document.writeln("<td>" + c + "/" + s + "/" + xchan);
      document.writeln("<td>sn");
      document.writeln("<td>vp");
      document.writeln("<td>vm");
      document.writeln("<td>temp");
      document.writeln("<td>d_vtpm/m_vtp");
      document.writeln("<td>d_thresh/m_thresha/m_threshb");
      document.writeln("</tr>");
    }
  }
  document.writeln("</table>");

  numpachan = xchan+1;
}

main();
reload();

//ODBSet('/Equipment/FgdWiener01/Settings/outputSwitch[8]', value);

    </script>

    <hr>
    <address><a href="xxx@xxx">Expt S1249</a></address>
<!-- Created: Tue Sep 21 15:44:39 PDT 2010 -->
<!-- hhmts start -->
Last modified: Wed Sep 22 08:30:31 PDT 2010
<!-- hhmts end -->
  </body>
</html>

> > We had javascript ODBGet() and ODBSet() functions for some time now, permitting 
> implementation of 
> > "page-reload-free" "self-updating" web pages. I finally got around to put all 
> the javascript bits together 
> > to actually implement such a page.
> 
> Unfortunately the page has tons of JavaScript errors, probably happened during 
> copy-and-paste to elog.

The attached errors all seem to be from cut-and-paste line breaks in the long "document.writeln()" statements. 
When the page runs, there are no errors from Firefox and Safari.

This example uses "document.writeln()" because the number of PostAmp devices displayed in the table is not 
known in advance and is potentially read from ODB at page load time.

K.O.

very recent mhttpd mangles spaces in URL encoding-decoding and I cannot create or delete entries in for 
example "/experiment/edit on start". For example attempt to delete "/experiment/Pedestals Run" 
produces:
<h1>Cannot find key Experiment/edit%20on%20start/Pedestals run</h1>
(notice "%20" instead of spaces. further navigation sometimes replaces the "%" sign with "%25" making it 
even more mangled)

this used to work. looks like a call to URL unmangling went missing somewhere.
K.O.

Please note that mlogger does not work (crashes on run start) starting with svn
rev 4858, fixed in svn 4862. If you have to use this busted version of mlogger,
the crash is fixed by update of history_midas.c to svn rev 4862 or set ODB
/Logger/WriteFileHistory to 'n'. Sorry for the inconvenience. K.O.

The following script makes midas very unhappy and eventually causes odb corruption. I suspect the reason is some kind of race condition collision between client 
creation and destruction code and the watchdog activity (each client periodically runs cm_watchdog() to check if other clients are still alive, O(NxN) total complexity). 
Amongst messages appearing in midas.log:

Thu Dec 23 11:59:08 2010 [ODBEdit28,INFO] Client 'unknown' on buffer 'SYSMSG' removed by bm_open_buffer because client pid 20463 does not exist
Thu Dec 23 11:59:09 2010 [ODBEdit43,INFO] Client 'unknown' on buffer 'SYSMSG' removed by cm_watchdog because client pid 20465 does not exist
Thu Dec 23 12:11:21 2010 [ODBEdit,ERROR] [odb.c:1061:db_open_database,ERROR] Removing client 'ODBEdit11', pid 21536, index 27 because the pid no longer exists
Thu Dec 23 17:06:15 2010 [ODBEdit,ERROR] [odb.c:988:db_open_database,ERROR] maximum number of clients exceeded
Thu Dec 23 12:10:30 2010 [ODBEdit9,ERROR] [odb.c:3247:db_get_value,ERROR] "Name" is of type NULL, not STRING

The last message about <"Name" is of type NULL> appears during normal operation of the ND280 DAQ, leading me into these investigations.

Notes:
a) the script runs at most 50 copies of odbedit, never exceeding midas.h MAX_CLIENTS value 64, so one does not expect to see messages about "maximum number of 
clients exceeded"
b) the script runs 50 copies of odbedit in parallel, increasing the likelihood of whatever race condition is causing this. In the ND280 system, likelihood of failure is 
increased by the large number of running clients (10-20-30 clients), each client running periodic cm_watchdog, to collide with new client creation or destruction.
c) in other experiments, we do not see this (ok, we do have midas meltdowns once in a while) because (1) we tend to have fewer clients (reduced frequency of 
cm_watchdog), (2) we tend to not start and stop midas clients too often (reduced frequency of running client creation and destruction). (NB it seems like ND280 people 
tend to run many scripts containing odbedit commands, so they effectively start and stop midas clients more often than usual).


#!/usr/bin/perl -w
#$cmd = "odbedit -c \'scl -w\' &";
$cmd = "odbedit -c \'ls -l /system/clients\' &";
for (my $i=0; $i<50; $i++)
{
system $cmd;
}
#end

> Thu Dec 23 12:10:30 2010 [ODBEdit9,ERROR] [odb.c:3247:db_get_value,ERROR] "Name" is of type NULL, not STRING

This is caused by a race condition between client removal in cm_delete_client_info() and cm_exist().

The race condition in cm_exist() works like this:
- db_enum_key() returns the hkey (pointer to) the next /System/Clients/PID directory
- the client corresponding to PID is removed, our hkey now refers to a deleted entry
- db_get_value() tries to use the now stale hkey pointing to a deleted entry, complains about invalid key TID.

Because the offending db_get_value() is called with the "create if not found" argument set to TRUE, there is potential
for writing into ODB using a stale hkey, maybe leading to ODB corruption. Other than that, this race condition seems
to be benign.

cm_exist() is called from:
everybody->cm_yield()->al_check()->cm_exist()

Further analysis:
- cm_yield() calls al_check() every 10 sec, al_check() calls cm_exist() to check for "program is not running" alarms.
- in al_check() cm_exist() is called once for each entry in /Programs/xxx, even for programs with no alarms. (Maybe I should change this?)
- assuming 10 programs are running (10 clients), every 10 seconds, cm_exist() will be called 10 times and inside, will loop over 10 clients, exposing the enum-get race condition 10*10=100 times every 10 seconds. Usually, 
ODB /Programs/ has many more entries than there are active clients, further increasing the frequency of exposure of this race condition.

K.O.

> > Thu Dec 23 12:10:30 2010 [ODBEdit9,ERROR] [odb.c:3247:db_get_value,ERROR] "Name" is of type NULL, not STRING
> This is caused by a race condition between client removal in cm_delete_client_info() and cm_exist().
> ... this race condition seems to be benign.

Not so benign - after fixing cm_exist() to check the return value of db_get_value() and calling it without the "create" flag,
a crasher turned up inside db_find_key() called by db_get_value() with these stale hkeys. For invalid keys (not TID_KEY),
it would call db_get_path() and crash.

So after adding a check for valid key types, my test script runs much better - all the major weirdness is gone, I only see
rare messages from db_find_key(), db_get_key() and db_get_value() about invalid key and data types (after all,
I did not fix the underlying race condition).

The only remaining problem when running my script is some kind of deadlock between the ODB and SYSMSG semaphores...

K.O.

> 
> The only remaining problem when running my script is some kind of deadlock between the ODB and SYSMSG semaphores...
> 


In theory, we understand how programs that use 2 semaphores to protect 2 shared resources can deadlock
if there are mistakes in how locks are used.

For example, consider 2 semaphores A and B and 2 concurrent
subroutines foo() and bar() running at exactly the same time:

foo() { lock(A); lock(B); do stuff; unlock(B); unlock(A); } and
bar() { lock(B); lock(A); do stuff; unlock(A); unlock(B); }

This system will deadlock immediately with foo() taking semaphore A, bar() taking semaphore B,
then foo() waiting for B and bar() waiting for A forever.

This situation can also be described as a race condition where foo() and bar() are racing each
other to get the semaphores, with the result depending on who gets there first
and, in this case, sometimes the result is deadlock.

In this example, the size of the race condition time window is the wall clock time
between actually locking both semaphores in the sequence "lock(X); lock(Y);". While
locking a semaphore is "instantaneous", the actual function lock() takes time to call
and execute, and this time is not fixed - it can change if the CPU takes a hardware
interrupt (quick), a page fault (when we may have to wait until data is read from the swap file)
or a scheduler interrupt (when we are outright stopped for milliseconds while the CPU runs
some other process).

In reality, subroutines foo() and bar() do not run at exactly the same time, so the probability
of deadlock will depend on how often foo() and bar() are executed, the size of the race condition time window,
the number of processes executing foo() and bar(), and the amount of background activity
like swapping, hardware interrupts, etc.

(Also note that on a single-cpu system, we will probably never see a deadlock between foo() and bar()
because they will never be running at the same time. But the deadlock is still there, waiting
for the lucky moment when the scheduler switches from foo() to bar() just at the wrong place).

There is more on deadlocks and stuff written at:
http://en.wikipedia.org/wiki/Deadlock
http://en.wikipedia.org/wiki/Race_condition

In case of MIDAS, the 2 semaphores are the ODB lock and the SYSMSG lock (also remember about locks
for the shared memory event buffers, SYSTEM, etc, but they seem to be unlikely to deadlock).

The function foo() is any ODB function (db_xxx) that locks ODB and then calls cm_msg() (which locks SYSMSG).

The function bar() is cm_msg() which locks SYSMSG and then calls some ODB db_xxx() function which tries to lock ODB.

(This is made more interesting by cm_watchdog() periodically called by alarm(), where we alternately
take SYSMSG (via bm_cleanup) and ODB locks.)

I think this establishes a theoretical possibility for MIDAS to deadlock on the ODB and SYSMSG semaphores.

In practice, I think we almost never see this deadlock because cm_msg() is not called very often, and during normal
operation, is almost never called from inside ODB functions holding the ODB lock - almost all calls to cm_msg from
ODB functions are made to report some kind of problem with the ODB internal structure, something that "never"
happens.

By "luck" I stumbled into this deadlock when doing the "odbedit" fork-bomb torture tests, when high ODB lock
activity is combined with high cm_msg() activity reporting clients starting and stopping, combined with a large
number of MIDAS clients running, starting and stopping.

So a deadlock I see within 1 minute of running the torture test, other lucky people will see after running an experiment
for 1 year, or 1 month, or 1 day, depending.

In theory, this deadlock can be removed by establishing a fixed order of taking locks. There will never be a deadlock
if we always take the SYSMSG lock first, then ask for the ODB lock.

In practice, it means that using cm_msg() while holding an ODB lock is automatically dangerous
and should be avoided if not forbidden.

And it does work. By refactoring a few places in client startup, shutdown and cleanup code, I made the deadlock "go away",
and my test script (posted in my first message) no longer deadlocks, even if I run hundreds of odbedit's at the same time.

Unfortunately,  it is impractical to audit and refactor all of MIDAS to completely remove this problem. MIDAS call graphs
are sufficiently complicated for making manual analysis of lock sequences infeasible and
I expect any automatic lock analysis tool will be defeated by the cm_watchdog() periodic interrupt.

An improvement is possible if we make cm_msg() safe for calling from inside the ODB db_xxx() function. Instead
of immediately sending messages to SYSMSG (requiring a SYSMSG lock), if ODB is locked, cm_msg() could
save the messages in a buffer, which would be flushed when the ODB lock is released. (This does not fix
all the other places that take ODB and SYSMSG locks in arbitrary order, but I think those places are not as
likely to deadlock, compared to cm_msg()).

However, now that I have greatly reduced the probability of deadlock in the client startup/shutdown/cleanup code,
maybe there is no urgency for changing cm_msg() - remember that if we do not call cm_msg() we will never deadlock -
and during normal operation, cm_msg() is almost never called.

Investigation completed, I will now cleanup, retest and commit my changes to midas.c and odb.c. Looking into this
and writing it up was a good intellectual exercise.

P.S. Also remember that there are locks for shared memory event buffers (SYSTEM, etc), but those do not involve
lock inversion leading to deadlock. I think all lock sequences are like this: SYSTEM->ODB, SYSTEM->SYSMSG->ODB,
there are no inverted sequences SYSMSG->SYSTEM or ODB->SYSTEM and the only deadlocking
sequence SYSTEM->ODB->SYSMSG, does not really involve the SYSTEM lock.

K.O.

A "nested" or "recursive" lock is a special type of lock that permits a lock holder to lock the same resources again and again, without deadlocking on itself. They are 
very useful, but tricky to implement because most system lock primitives (SYSV semaphores, POSIX mutexes, etc) do not permit nested locks, so all the logic for 
"yes, I am the holder of the lock, yes, I can go ahead without taking it again" (plus the reverse on unlocking) has to be done "by hand". As ever, if implemented 
wrong or used wrong, Bad Things happen. Many people dislike nested locks because of the added complexity, but realistically, it is impossible to build a system 
that does not require nested locking at least somewhere.

MIDAS lock primitives - ss_semaphore_wait_for(), db_lock_database() and bm_lock_buffer() implement a type of nested locks.

ODB locks implemented in db_lock_database() fully support nested (recursive) locking and this feature is heavily used by the ODB library. Many ODB db_xxx() 
functions take the ODB lock, do something, then call another ODB function that also takes the ODB lock recursively. This works well.

Unfortunately, the ODB nested lock implementation is NOT thread-safe. (Unless one is connected through the mserver, in which case, db_xxx() functions ARE 
thread-safe because all ODB access is serialized by the mserver RPC mutex).

Event buffer locks implemented in bm_lock_buffer() rely on ss_semaphore_xxx() to provide nested locking.

ss_semaphore_wait_for() uses SYSV semaphores, which do not provide nested locking, except when called from cm_watchdog(). (keep reading).

Because bm_lock_buffer() does not implement nested locking, use of cm_msg() in buffer management code will lead to self-deadlock, as shown in the following 
stack trace, where bm_cleanup() is working on the SYSMSG buffer, locked it, then called cm_msg() which is now waiting on the SYSMSG lock, which we are holding 
ourselves.

(gdb) where
#0  0x00007fff87274e9e in semop ()
#1  0x0000000100024075 in ss_semaphore_wait_for (semaphore_handle=1179654, timeout=300000) at src/system.c:2280
#2  0x0000000100015292 in bm_lock_buffer (buffer_handle=<value temporarily unavailable, due to optimizations>) at src/midas.c:5386
#3  0x000000010000df97 in bm_send_event (buffer_handle=1, source=0x7fff5fbfd430, buf_size=<value temporarily unavailable, due to optimizations>, 
async_flag=0) at src/midas.c:6484
#4  0x000000010000e6f5 in cm_msg (message_type=2, filename=<value temporarily unavailable, due to optimizations>, line=4226, routine=0x10004559f 
"bm_cleanup", format=0x100045550 "Client '%s' on buffer '%s' removed by %s because process pid %d does not exist") at src/midas.c:722
#5  0x000000010001553c in bm_cleanup_buffer_locked (i=<value temporarily unavailable, due to optimizations>, who=0x100045f42 "bm_open_buffer", 
actual_time=869425784) at src/midas.c:4226
#6  0x00000001000167ee in bm_cleanup (who=0x100045f42 "bm_open_buffer", actual_time=869425784, wrong_interval=0) at src/midas.c:4286
#7  0x000000010001ae27 in bm_open_buffer (buffer_name=<value temporarily unavailable, due to optimizations>, buffer_size=100000, 
buffer_handle=0x10006e9ac) at src/midas.c:4550
#8  0x000000010001ae90 in cm_msg_register (func=0x100000c60 <process_message>) at src/midas.c:895
#9  0x0000000100009a13 in main (argc=3, argv=0x7fff5fbff3d8) at src/odbedit.c:2790

This example deadlock is not a normal code path - I accidentally exposed this deadlock sequence by adding some extra locking.

But in normal use, cm_msg() is called quite often from cm_watchdog() and as protection against this type of deadlock, MIDAS
ss_semaphore_xxx() has a special case that permits one level of nesting for locks called by code executed from cm_watchdog(). This is a very
clever implementation of partial nested locking.

So again, we are running into problems with cm_msg() - logically it should be at the very bottom of the system hierarchy - everybody calls it from their most 
delicate places, while holding various locks, etc - but instead, cm_msg() call the whole MIDAS system all over again - it calls ODB functions, event buffer functions, 
etc - mostly to open and to write into the SYSMSG buffer.

If you are reading this, I hope you are getting a better idea of the difference between textbook systems and systems that are used in the field to get some work 
done.

K.O.

> 
> The only remaining problem when running my script is some kind of deadlock between the ODB and SYSMSG semaphores...
> 


I committed changes to odb.c and midas.c fixing a number of places that could corrupt ODB and SYSMSG data, and fixing a number of deadlocks. Without these 
changes, on my Mac, MIDAS will reliably corrupt ODB or deadlock while running my odbedit fork-bomb torture test script. These changes still need to be tested on 
Linux (but I do not expect any problems).

Because my changes do not fix the original race condition in client creation/removal/cleanup, you may still occasionally see messages like this:
13:35:14 [ODBEdit24,ERROR] [odb.c:2112:db_find_key,ERROR] hkey 169592 invalid key type 376
13:35:15 [ODBEdit28,ERROR] [odb.c:3268:db_get_value,ERROR] hkey 162072 entry "Name" is of type NULL, not STRING

For now, I am happy that we no longer corrupt ODB (nor deadlock) and I will work with Stefan on a permanent solution for this.

Special thanks go to the T2K/ND280 experiment, specifically, to Tim Nicholls and to the unnamed person who emailed me their script that executes many odbedit 
commands to setup midas history plots.


svn rev 4930
K.O.


P.S. Below is my torture test script, I usually run many of them in a sequence "./test1.perl >& xxx1; ./test1.perl >& xxx2; ... etc".

#!/usr/bin/perl -w
for (my $i=0; $i<50; $i++)
{
#my $cmd = "odbedit -c \'scl -w\' &";
#my $cmd = "odbedit -c \'ls -l /system/clients\' >& xxx$i &";
my $cmd = "odbedit -c \'ls -l /system/clients\' &";
system $cmd;
}
#end

svn rev 4930
K.O.

> > 
> > The only remaining problem when running my script is some kind of deadlock between the ODB and SYSMSG semaphores...
> > 
> 
> For now, I am happy that we no longer corrupt ODB (nor deadlock) ...
>

Found one more deadlock between ODB and SYSMSG semaphores, this time through cm_watchdog():

If cm_watchdog somehow runs while we are holding the ODB semaphore, it will eventually try to lock SYSMSG (through bm_cleanup & co) in
violation of our semaphore locking order. If at the same time another application tries to lock stuff using the correct order (SYSMSG first, ODB last),
the two programs will deadlock (wait for each other forever). I presently have two copies of gdb attached to two copies of odbedit
waiting for each other in a deadlock through this cm_watchdog scenario...

Solution shall follow quickly, I have been hunting this deadlock for the last couple of weeks...

K.O.

> Solution shall follow quickly, I have been hunting this deadlock for the last couple of weeks...

Over the last couple of days I made a series of commits to odb.c and midas.c to implement a buffer-based cm_msg()
and fix the latest deadlock problem, also to help with the race conditions in client creation and cleanup.

My torture test runs okey in my mac now, one remaining problem is spurious client removal caused
by semaphore starvation - I see 2-3-7-10 sec wait times for semaphores - probably caused by some
kind of unfairness in the MacOS SysV semaphore implementation (in a "fair" semaphore implementation,
the process that waited the longest would be woken up the first and one would never see semaphore wait
times measured in seconds). Probably worth investigating fairness of MacOS posix semaphores. On LInux
things are probably different and under normal running conditions one should not see any semaphore starvation.

I will be doing extensive tests of this update at TRIUMF, but I do not expect any problems. If you use this
version and see any anomalies, please report them as replies to this message or email me directly.

svn rev 4976
K.O.

The mlogger has a function for detecting when the output disk becomes full - when this condition is 
detected, the run should be stopped. But this did not work if disk is already full and the user tries to start 
a run - the "disk full?" check happened too early and the attempt to stop the run was not succeeding 
because the original start-run transition is still running. Now if "disk full" condition is detected, mlogger 
tries to stop the run every 10 seconds until the run is finally stopped (or dies because disk is full).

mlogger.c svn rev 4976
K.O.

Some notes on the MIDAS history.

MIDAS documentation at
http://midas.psi.ch/htmldoc/F_History_logging.html
describes:

- midas equipment concepts
- midas equipment event ids
- midas data banks
- midas history concepts
- history records (correspond to data banks)
- history record ids (correspond to equipment ids)
- history tags (describe the structure
- describes the code path from the user read function through odb to the mlogger to the history file
- midas history file internal data format
- documents the tool for looking inside history files - mhdump

But some things remain unclear after reading the documentation - where are the history definitions 
saved? what happens if an equipment is deleted or renamed? what's all the mumbling about 
/History/Events and /History/Tags? what's this /History/PerVariableHistory?

As I go through my review of the MIDAS history code, I will attempt to clarify some of this information.

1) PerVariableHistory.

The default value of 0 is intended to operate the midas history in "traditional" mode. In this mode:
- there is one history record for each equipment
- history record id is equal to the equipment id
- /History/Events and /History/Tags are not required and can be safely deleted

The downside of this history mode is that there is only one history record per equipment. If some 
equipment has many banks not all of which are updated all at the same time, every time one bank is 
updated, data for all banks is written to the history file, even if data in all those other banks had not 
changed. The result is undesired duplication of data in midas history files. In turn, this leads to slow 
down while making history plots (mhttpd has to read more data from bigger data files, which takes time) 
and for long running experiments may pose problems with disk space for storing history files.

In addition, when logging history data into an SQL database, each history record is mapped into an SQL 
table, so all variables from all banks of an equipment end up in the same SQL table - and in addition to 
data duplication described above, a data presentation problem is created - database users and 
administrators dislike having SQL tables with "too many" columns!

To solve both problems - reduce data duplication and avoid creating over-large SQL tables - per-
variable history has been implemented.

to be continued...

K.O.

> I have the following problems after updating to midas SVN 4936: the history 
> system (web-page via mhttpd) seems to stop working. I checked the history files 
> themself and they are indeed written, except that the events ID's are not the 
> same anymore (I mean the ones defined under /Equipment/XXX/Common/Event ID), 
> rather the mlogger seems to choose an ID by itself.

Yes, I found the problem - it was introduced around svn rev 4827 in September 2010.

It is fixed now, please do this:
1) update history_midas.c to latest svn rev 4979
1a) do NOT update any other files - update only history_midas.c
2) rebuild mlogger (it will do no harm and no good if you rebuild everything)
3) odbedit save odb.xml
4) in odb, remove /history/events and /history/tags (you can also set "/History/DisableTags" to "y")
5) restart mlogger
6) observe that odb /history/events now has event ids same as equipment ids
7) restart your frontend, observe that history file is growing
8) use mhdump to observe that history is now written with correct event id
9) go to mhttpd history plot, you should see the new data coming in. Plot history in the "1 year" scale, you 
should see the old data and you should see a gap where data was written with wrong event id
10) I should still have  an mhrewrite program sitting somewhere that can change the event ids inside midas 
history files, if you have many data files with wrong event id, let me know, I will find this program and tell you 
how to use it to repair your data files.

> Currently the only way to get things working again was to recompile midas with 
> adding -DOLD_HISTORY to the CFLAGS which is troublesome since it is likely to be 
> forgotton with the next SVN update.

Yes, I am glad you found OLD_HISTORY, I kept it just for the case some breakage like this happens. I will still 
keep it around until the dust settles.

> When looking into the SVN I have the  impression there is something going on concerning the history 
system, however I couldn't find any documentation.

Yes, you found the right stuff, and it is partially documented. mlogger uses /History/Events to map history 
event names (equipment names in your case) to history event ids. But in your case, the wrong event id has 
been assigned by mlogger so nothing worked right. As a bonus, I now see inconsistency between event_id 
code remaining in mlogger (which is not used) and event_id code in history_midas (which *is* used). I will be 
straightening this stuff over the next few days.

I hope my correction to history_midas.cxx is good enough to get you going for now.

> What is the best practice for the future, in order not to run into any problems 
> but still being able to look at the old history (also from within the web-page 
> via mhttpd)?

Personally, I think that the midas history storage into binary files is not robust enough
when facing changes to equipment and event ids, renaming and deleting of stuff, etc. There
are other limitations, as well, i.e. the 16-bit history event id, etc.

The newly implemented SQL history storage (uses ODBC layer, MySQL supported, PgSQL partially
implemented) does not have any of these problems and seems to work well enough
for T2K/ND280. Sometimes MySQL history is even faster when making history plots in mhttpd.

I am now thinking about implementing SQL history storage in SQLite files, and it will not have
any of these problems, too. Performance and robustness for database corruption remain a question, though.

K.O.