<!-- Title: 17:15:25  Mon Jun  4 2007 -->
<!-- Crewchief: cdf_daq -->
<!-- Op1: &nbsp; -->
<!-- Op2: &nbsp; -->
<!-- Op3: &nbsp; -->
<!-- Op4: &nbsp; -->
<!-- Op5: &nbsp; -->
<!-- Op6: &nbsp; -->
<!-- Notes: -->
<b><font color="#ff3399">June, 2007</font></b>


<!-- Date: Mon Jun 4 17:38:09 2007 -->
<b>Calibration CSL quick test</b><p> 
Tried to bring up calibration csl code using "setup calibcsl". Log files are directed correctly to new area(/cdf/scratch/cslace/log). 
However, it did not work in below cases.  
<p> 
<li> Username = cslace,  project name = cdf_daq, with "-r" option.<br> 
<ul> This is same environmental variable setup with main csl. did not work with error. 
<pre> 
[15791] ERROR--> hostname: b0server03.fnal.gov 
         prg name: $Id: csl_driver.c,v 1.1.1.1 2007/05/16 17:20:38 gbyu Exp $ 
         function: main() 
         datetime: Mon Jun  4 16:41:46 2007 
         src file: /cdf/onln/code/cdfprod/calibcsl/v0/src/programs/csl_driver.c 
         src line: 860 
         src info: There is an existing cs-l using the same project name 
</pre> 
option -r in csl_driver: (run control) option listens to run control. 
</ul> 
</li> 
<li> Username = cslace,  project name = cdfdaq, with "-r"<br> 
<ul> did not work either. Somehow the project name is reset to cdf_daq. The "cdf_daq" is hardcorded explicly once other than the script. 
<pre> 
src/library/csl_diskinfo_send.c:  TutOptionSetEnum(option, "cdf_daq"); 
</pre> 
</ul> 
</li> 
<li> Username = cslace, without "-r" <br> 
<ul> Without "-r", the csl_driver code use environment of "User". So, still there were errors about existing cs/l. The only solution is to change /csl to /calibcsl for communication to run control.  
</ul> 
</li> 
<li> Username = cdfdaq, without "-r" <br> 
<ul> This only works in the test. The setup is also same as the current calibration csl. A couple of calibration run were taken, one was okay and the next one was stuck (TOF TAC). Don't know why .. Log files were directed correctly to new area (/cdf/scratch/cslace/log). 
</ul> 
</li> 
<p> 
<b>Next to do </b>is to change "/csl" to "/calibcsl" to make the calibration csl communicate to run control. The project name should be "cdf_daq", so that we must change the user.   
<!-- Author: Geumbong -->


<!-- Date: Tue Jun 5 11:35:19 2007 -->
Test files remained in .open directory(b0csl23,24,25,27) were from daq test by Nils.  
Since there were no request to retrieve those them over 1 day, I removed them. 
<!-- Author: Geumbong -->


<!-- Date: Wed Jun 6 13:14:09 2007 -->
<b><font color=red>Calibration CSL test</font></b> 
<p> 
The calibration csl gets started with  
<pre> 
subject name = calibcsl 
project name = cdf_daq 
 
========================================================== 
<--------- internal state is WAITING, waiting for command ---------> 
13:09:24:            SetPartition Received. 
13:09:24:            message destination : /setPartition/calibcsl 
13:09:24:            message sender      : /_b0server03.fnal.gov_23a08bf 
           time received       :  06/06/13:09 
========================================================== 
</pre>
<!-- Author: Geumbong -->
<!-- Comment: Wed Jun  6 13;50;15 comment by...Geumbong, Frank, Willis -->
ACE ran bunch of calibration while calibration csl, v0, working, but failed. It turned out run control still tries to connect to "/csl", not "/calibcsl". Asked Bill why. 


<!-- Date: Sat Jun 9 15:44:52 2007 -->
<pre>The CSL problem related to L2/L3 problem. 
Run 243219 record funny very high L3 output(~240Hz) and L3 was stuck. CSL also stuck due to high rate. 
 
According to receiver log, CSL got many event counts and happened max client error, too. 
 
After restarting, CSL is back to normal sate. 
 
[243219] csl_receiver_run_event: [run 5804] event 4096, byte count is 1402564578 
[243219] csl_receiver_run_event: [run 5807] event 4096, byte count is 1406387560 
[243219] csl_receiver_run_event: [run 5803] event 4096, byte count is 1410635323 
[243219] csl_receiver_run_event: [run 5810] event 8192, byte count is -1486735219 
[243219] csl_receiver_run_event: [run 5760] event 8192, byte count is -1476967227 
[243219] csl_receiver_run_event: [run 5804] event 8192, byte count is -1480054618 
 
 
[14355] ERROR--&gt; hostname: b0csl20.fnal.gov 
         prg name: $Id: csl_receiver.c,v 1.104 2007/04/19 21:41:05 richard Exp $ 
         function: csl_receiver_child_body() 
         datetime: Sat Jun  9 13:05:50 2007 
         src file: /cdf/onln/code/cdfprod/csl/v2_7/src/programs/csl_receiver.c 
         src line: 1336 
         src info: no more than 16 receiver client connections available 
</pre>
<!-- Author: tatsuya -->
<!-- Comment: Sat Jun  9 15;45;32 comment by...tatsuya -->
<pre>By the way, byte count was overflow. Is this normal?</pre>

<!-- Comment: Sun Jun 10 00;30;16 comment by...Willis -->
<p>The byte count problem has been around for a while. I think
   it should be addressed in v2_8.
</p>
<p>After the high L3 rate froze the CSL, does anyone know why
   it took about 4 tries to restart the CSL? Most of the 
   failures were "config" errors where the csl_driver was not
   able to start up the rest of the CSL.
</p>

<!-- Comment: Sun Jun 10 15;42;18 comment by...Geumbong -->
The first CSL stop mail indicated that there were csl logger queues got stuck at logger as well as maximum client error. The csl got stuck more often than expected recently.. From naive calculation, csl is supposed to digest at least up to 320Hz. 
<pre>
========================
MESSAGE QUE INFO :
 available : 2
QUEUES :
 receiver : 0
 logger : 217
 distributor : 1
 conssend : 0
 driver : 0
 monitor : 0 
========================
</pre>

<!-- Comment: Sun Jun 10 16;56;43 comment by...Geumbong -->
Again stream D client connection was broken and redirected to b0csl21. More Look at log file for csl_logger is following:
<pre>
csl_logger_b0csl20
========================
 *** Break *** write on a pipe with no one to read it
[00d] Stream has shutdown abruptly!
[00d] Run section truncated: 16
[00d] Performing connection recovery, discarding remainder of this run section.
[00d] Choosing new logger node b0csl21-private:9000 for stream d
[00d] Sending handshake for re-connection of stream d
[00d] Connection died on run section section: 16
[00d] Connection recovery resuming on run section: 17
========================
</pre>
More than 4000 events were recorded at b0csl21. This redirection client logger was not the cause of logger queue filling up.

<pre>
csl_logger_b0csl21, child logger
============================
[00d] New file opened: /mnt/data1/logger/ace/00/.open/dr03b613.0015phys
[00d] File closed: /mnt/data1/logger/ace/00/dr03b613.0013phys
[00d] [4194 events; 1707343103 bytes:written; 1711324290 bytes:filesize; 24 MB/s]
[00d] DB file written: /mnt/data1/logger/ace/00/dr03b613.0013phys.db [RS min = 19 max = 19]
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/dr03b613.0015phys already exists

--------------------------------------------------------------------------------
ERROR--> hostname: b0csl21.fnal.gov
         prg name: $Id: csl_logger_client.c,v 1.8 2007/04/10 22:11:39 richard Exp $
         function: csl_logger_openfile()
         datetime: Sat Jun  9 12:59:22 2007
         src file: /cdf/onln/code/cdfprod/csl/v2_7/src/programs/csl_logger_client.c
         src line: 1464
         src info: [00d] Error opening output file: dr03b613.0015phys
         sys perr: File exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/dr03b613.0015phys already exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/dr03b613.0015phys already exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/dr03b613.0015phys already exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/dr03b613.0015phys already exists

 *** Break *** write on a pipe with no one to read it

==============================
</pre>
I would say this is why the CSL got stuck and L3 turned to green.
Client logger opened two files with same name and got error.  
We had experience about this problem cause logger queue filling up, and it happened again. 

<!-- Comment: Sun Jun 10 17;23;09 comment by...Geumbong -->
<b>The Missing files from file manifest check</b><p>
b0csl25 :
<pre>
None             0       Sat Jun  9 12:55:42 2007       1181411742      dr03b613.000ephys
None    1825578449       Sat Jun  9 12:56:36 2007       1181411796      dr03b613.000fphys       dr03b613.000fphys
None     247996636       Sat Jun  9 12:56:40 2007       1181411800      dr03b613.000fphys_dr03b613.000fphys_split
None             0       Sat Jun  9 12:56:40 2007       1181411800      dr03b613.0010phys


Files remain in .open:
79:b0csl25 % cd /mnt/data1/logger/ace/00/.open
80:b0csl25 % lsr
total 3.3G
-rw-r--r--  1 cslace cdf 1.8G Jun  9 12:56 dr03b613.000ephys
-rw-r--r--  1 cslace cdf 205M Jun  9 12:56 dr03b613_1.000ephys
-rw-r--r--  1 cslace cdf  306 Jun  9 12:56 dr03b613.0010phys
-rw-r--r--  1 cslace cdf  306 Jun  9 13:34 dr03b615.0014phys
</pre>
It seems weird because file split worked for "000f"
 section but did not work for previous section "000e".
<p>
b0csl21:
<pre>
None    1825715472       Sat Jun  9 12:57:44 2007       1181411864      dr03b613.0011phys       dr03b613.0011phys
None     105785756       Sat Jun  9 12:57:46 2007       1181411866      dr03b613.0011phys_dr03b613.0011phys_split
None    1825541018       Sat Jun  9 12:58:21 2007       1181411901      dr03b613.0012phys       dr03b613.0012phys
None    1707343103       Sat Jun  9 12:59:22 2007       1181411962      dr03b613.0013phys       dr03b613.0013phys
None     219226941       Sat Jun  9 12:58:51 2007       1181411931      dr03b613.0012phys_dr03b613.0012phys_split
None    1101749127       Sat Jun  9 12:59:22 2007       1181411962      dr03b613.0014phys_dr03b613.0014phys_split
None             0       Sat Jun  9 12:59:22 2007       1181411962      dr03b613.0015phys

File remain in .open:
-rw-r--r--  1 cslace cdf 306 Jun  9 12:59 dr03b613.0015phys
</pre>
The dr03b613.0014phys_split is splited from "0013phys".


<!-- Date: Thu Jun 14 18:44:36 2007 -->
<b>Calibration CSL now works!</b> 
<ul> 
<li>The problem: The CVS/UPS version of the calibration 
    CSL (ie, the setup calibcsl package) did not distribute 
    events to the calibration consuers.</li> 
<li>The DEBUG option was set in the makefile, and this 
sets CSL_LOGGER_MAX_STREAM=2. However, the calibration 
stream that the csl_receiver gets from the event 
builder is stream I (8). So, the csl_receiver puts 
message_types correponding to stream 8 into the 
message queues. The csl_logger was using stream=-1. 
The section of code in the csl_logger that forks off a 
slave child logger checks Global_logger_slave[stream]. 
This was undefined for stream=8, and no slave child logger 
was forked off. The section of code that forks off this 
slave child logger sets the csl_logger global stream 
variable to the appropriate stream. So, the csl_logger did 
not set the correct stream via the csl_trigger_return_stream 
function, and hence the csl_logger code used stream=-1 (ie, 
no stream).</li> 
<li>When we set CSL_LOGGER_MAX_STREAM=10, the calibration 
CSL ran without problems.</li> 
<li>Without Mako&#39;s help, it would have taken us a lot 
    longer to solve this.</li> 
</ul>
<!-- Author: Geum Bong, Willis -->


<!-- Date: Mon Jun 18 20:09:34 2007 -->
<p>The new calibration CSL was tested with all the consumers: 
   They all ran OK. The main CSL was turned off for part of the 
   test to see if run control would hang during calibrations 
   -- It did not hang. 
</p> 
<p>We declare success, and leave the new calibration CSL 
   running. This new version will be made the default. 
</p>
<!-- Author: Geum Bong, Ilija, Willis -->
<!-- Comment: Tue Jun 19 11;37;55 comment by...Geumbong -->
The changes for making calibcsl work are committed to cvs-calibcsl- and tagged as v0. Also the development version of calibcsl is created, v1. Please update it or commit updates to "calibcsl" if needed. 
<pre>
lrwxrwxrwx    1 cdfprod  cdfprod        34 May 16 12:24 current -> /cdf/onln/code/cdfprod/calibcsl/v0
drwxrwxr-x   19 cdfprod  cdfprod      4096 May 21 14:50 v0
drwxrwxr-x   18 cdfprod  cdfprod      4096 Jun 19 11:33 v1
lrwxrwxrwx    1 cdfprod  cdfprod        34 Jun 19 11:33 devel -> /cdf/onln/code/cdfprod/calibcsl/v1
</pre>


<!-- Date: Wed Jun 20 18:43:25 2007 -->
<b>CSL_LOGGER_LAST_RUN error showed up today!</b> 
Please see the link -   
<a href= 
'http://www-cdfonline.fnal.gov/cgi/elog/elog.pl?nb=2007&action=view&page=512&frame=2&anchor=14:30:08.161'> 
shift e-log</a>. 
Today, csl decided to end run when it got timedout from connection to run control. Such message showed up in "csl_logger_b0csl20" log file: 
<pre> [00 ] Sending ETimedout Run Summary</pre> 
, which is issued whenever there's run time error. By looking at recent error loggers, the run time error arose related with L2 problem and shift crew did restart run. However, at this time, ace recorvered run and it caused "LAST_RUN" error. As mentioned before, csl already decided to end run. 
<!-- Author: Willis, Geumbong -->


<!-- Date: Fri Jun 22 21:13:01 2007 -->
<p>I ran a test of v2_9 after putting print statements into 
csl_mon_send to try and find out why the AverageEventSize 
field in the CSL Run summary web page is a large negative 
number for some runs. It did not work. I used the plug laser runs 
as they always seem to have the large, negative AverageEventSize. 
The puzzling thing is that the data in csl_mon_send appears to 
be okay. 
</p>
<!-- Author: Willis -->


<!-- Date: Mon Jun 25 09:22:23 2007 -->
<pre>JJ just paged me that he was informed that the switch to feynman is dead since yesterday. He will leave it in this configuration so that we can find out how to notice such an occurrence and decide how and who will coordinate the replacement with the spare switch.</pre>
<!-- Author: Ilija -->
<!-- Comment: Mon Jun 25 19;07;32 comment by...Email from Frank -->
<pre>Hi

The CSLOGGER switch is dead. It looks like the power supply on it has
failed. This switch is managed by datacomm and should be replaced as
soon as possible.

JJ contacted Dave Tang about the switch and will told them to go ahead
and arrange to replace it.

We should monitor this switch so that we can tell if there is a problem
One way to do this would be to add a "Path Status" line to the
"CSL To Enstore Status" web page which checks for connectivity between
the csl logger node and the 215 subnet. In case the path is down it should
indicate so on the web page and also send an email message out indicating
so and also we should have a way for cslmon to know of the problem.

I talked with Dehong and suggested the following changes to the "CSL To Enstore Status"
page:

1) Add line indicating if the path to feynman is ok
    Path to Feynmann OK|DOWN
2) If the time of last update is longer than x mins change the color to red.
3) If the path to Feynman is down - send out an email message indicating so
4) If the path to Feynman is down - provide some way for CSLMON to recognize
    the problem.

    One place you can find out if there is a problem is from the URL:

       http://www-cdfonline.fnal.gov/daq/cslmon/stager/status.txt

    but this does not explicitly indicate that the problem is because of
    the switch.

Also, instructions on how the switches are configured is located on the
"Experts Link" web page. We should review the instructions to make sure that
they are clear.</pre>


<!-- Date: Mon Jun 25 19:09:21 2007 -->
<center><a href='/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-22&button=yes' target='xxx' onclick='jswindow()'><img src='/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-23' ></a><a href='/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-24&button=yes' target='xxx' onclick='jswindow()'><img src='/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-25' ></a></center>
<!-- Author: gbyu -->
<!-- Comment: Mon Jun 25 19;10;10 comment by...Geumbong -->
Enstore enabled after ps of 215 subnet switch was fixed. 


<!-- Date: Mon Jun 25 19:16:40 2007 -->
<pre> 
Hi, 
 
I am looking for the data file from a test run we took yesterday.  The 
run number is 243966.   It was a short L2 torture run where I specified 
data type DAQTEST_TORTURE which is data type =5.     No files 
showed up in the look area, though.    I assumed that since we selected 
this data type that we were not writing the events to trash. 
 
 
thanks, 
  Kevin 
</pre> 
The datatype = 5 should work same as datatype = 4. Rich confirmed this, but it did not at that time. We will ask a request to reproduce this with L2 torture in between stores. Below is from the logger log file from run 243966,stream I. 
<pre> 
================================= 
 csl_logger_b0csl20 apparentely sent data to b0csl28, 
and parent logger received events. 
  ============================ 
[N/A] Connection from 192.168.2.20:53766 
[00i] Run number is 243966 
[00i] Lookarea policy 3 in effect. 
[00i] Run type index 5 in effect. 
[00i] Run type test in effect. 
[N/A] Child 7827 terminated (status = 0) at Fri Jun 22 19:29:51 2007 
  ============================ 
 
 And below is the client logger log message: 
 ============================ 
61:b0csl28 % more csl_logger_0i.out_1182558425 
Logging to /cdf/scratch/cslace/log/csl_logger_b0csl28/csl_logger_0i.out_1182558425 (descriptor 2). 
[00i] Child receiver logger 7827 is born (stream i/partition 0 -> 192.168.2.20:53766) at Fri Jun 22 19:27:05 2007 
 
[00i] Thread is managing stream i/partition 0 on fd 8 
[00i] csl_logger_child_recv_in: received CSL_STREAM_SHUTDOWN from receiver node 
[00i] csl_logger_child_recv_in: enqueueing return CSL_STREAM_SHUTDOWN for receiver node 
[00i] csl_logger_child_send_out: sending CSL_STREAM_SHUTDOWN to receiver node 
[00i] csl_logger_child_cb_dispatch: dequeuing CSL_STREAM_SHUTDOWN for local logger 
[00i] Received shutdown message for partition 0 stream 8; pid 7827 terminating... 
[00i] csl_logger_child_send_out exiting... 
[00i] csl_logger_child_cb_dispatch exiting... 
[00i] csl_logger_child_recv_in exiting... 
[00i] Child receiver logger 7827 is finished (stream i/partition 0 -> 192.168.2.20:53766) at Fri Jun 22 19:29:51 2007 
 ============================= 
</pre>
<!-- Author: Geumbong -->


<!-- Date: Wed Jun 27 14:44:06 2007 -->
<b> datatype = 5 works! </b><p> 
It works in l2 torture... I have no idea why...  
<pre> 
None	 941214955	 Wed Jun 27 11:59:04 2007	1182963544	ir03ba09.0001test	ir03ba09.0001test 
None	 649789899	 Wed Jun 27 14:43:01 2007	1182973381	ir03ba22.000etest	ir03ba22.000etest 
</pre>
<!-- Author: Geumbong -->


<!-- Date: Wed Jun 27 15:30:51 2007 -->
<p>CSL v2_9 test: The CSL run summary page had large negative 
   numbers in the event and data rate entries. The end run 
   CSL summary is provided by the csl_logger&#39;s  
   csl_logger_send_run_summary(), and it was not passing on 
   rate information. The run control side is  
   expecting entries in these fields for both polling and 
   end run messages. The rate fields were added to the 
   v2_9 version of csl_logger.c, and so it is now the same 
   as the polling message provided by csl_mon_send.c. 
</p>
<!-- Author: Geum Bong, Ilija, Willis -->


<!-- Date: Wed Jun 27 19:30:07 2007 -->
<p>More CSL tests: csl_logger.c appears to have been undercouting 
   events for the run control in-run and end of run CSL 
   summary. The code is in 
   csl_logger_log_event(...). The event is first logged, then 
   the monitoring code collects statistics. The monitoring code 
   first checks if the logger state is CONNECTED, and if so, 
   it changes the state to ACTIVE and does initializations. 
   However, it did not collect statistics on this event. 
   Changing the code so that it collects statistics on all 
   L3_CS_RUN_EVENTs eliminates the discrepancy. 
</p>  
<!-- Author: Geum Bong, Ilija, Willis -->


<!-- Date: Tue Jul 24 00:24:08 2007 -->
<pre>Today we had a lot of problems with logger message queues filling up, the ace had to restart CSL several times before it worked. 
 
Apparently it happened after they started using L2torture, which has the L2 tag 698, the same is also used in AAA_CURRENT so if the problems are due to faulty triggers we might see this again during data-taking. 
 
I have checked the log files on b0csl20 and what i could find is the following errors (a lot of them): 
 
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0]  
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0]  
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0]  
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0]  
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0]  
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0]  
Run: [245629], Partition [0].  Receiver [7]. Warning !!!! Event did NOT have a stream !!!!  Counter = [0] 
 
(From the older logs these messages were seen before)</pre>
<!-- Author: Ilija Bizjak -->
<!-- Comment: Tue Jul 24 00;27;31 comment by...Ilija Bizjak -->
<pre>Logs with these messages are on b0csl20:
/cdf/scratch/cslace/log/csl_receiver/csl_receiver.out_070723xxxx

</pre>

<!-- Comment: Tue Jul 24 00;44;23 comment by...Ilija Bizjak -->
<pre>Sorry, I meant L3 tag</pre>


<!-- Date: Tue Jul 24 02:13:14 2007 -->
<table><tr><td><a href=/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-28&button=yes target='xxx' onclick='jswindow()'; align=top><img src=/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-29  width='300' align='top'></a></td><td>Today's number of process in main CSL</td></tr></table>
<!-- Author: Tatsuya -->


<!-- Date: Tue Jul 24 02:14:17 2007 -->
<center><a href='/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-26&button=yes' target='xxx' onclick='jswindow()'><img src='/cgi/elog/det-system-elog.pl?nb=cs-logger&action=view&page=-27' ></a></center>
<!-- Author: tatsuya -->
<!-- Comment: Tue Jul 24 02;42;40 comment by...Tatsuya, Hideki, Yoshiakazu  -->
<pre>This histroy plot is number of receiver process. 
After 2pm receiver process goes up to over 16 and after that same issues happen some times.
I don't see more infomation from following log file. Ace tried to restart many times. But it was not fixed. I also try to restart CSL again. It is working now. 

I don't understand why max client error happens many times.

[15977] ERROR--&gt; hostname: b0csl20.fnal.gov
         prg name: $Id: csl_receiver.c,v 1.105 2007/06/05 18:31:17 richard Exp $
         function: csl_receiver_child_body()
         datetime: Mon Jul 23 14:22:12 2007
         src file: /cdf/onln/code/cdfprod/csl/v2_8/src/programs/csl_receiver.c
         src line: 1342
         src info: no more than 16 receiver client connections available
</pre>

<!-- Comment: Tue Jul 24 02;45;47 comment by...Tatsuya -->
<table border=0><td><tr><td bgcolor=#e0e030><pre>When I tried to understand it I noticed  partition 14 on b0desktop01. I stop it though I don't know how long does it work and it affect in this problem. If someone study using partition 14. Please restart again. </pre></td></tr></td></table>


<!-- Date: Tue Jul 24 18:21:43 2007 -->
<pre>== Run245704 == 
 
According to run summary, 140 no stream events are recorded which is same number as number of logger queues in cslmon. However, I cannot find such many "No stream warnings" from neither receiver nor logger log files. Something has not been treated properly in csl processes..  </pre>
<!-- Author: Geumbong -->


<!-- Date: Wed Jul 25 12:15:18 2007 -->
<b>Summary of the problems since Monday evening. </b> 
<ol> 
<li> The symptom(csl logger queues filling up & max client error after several minuits) was found when three quarter of level3 farm turned to gray. </li> 
<li> Logger queues were filled up with NO stream events according to CSL run summary, but they seems to have currupted header (dumped message queues when stopping csl). 
<pre> 
 
++++ Dumped message when csl logger queues were full  today ++++ 
 
 type         buffer type  length strms  format part    run  evtnum section 
------------------------------------------------------------------------------ 
1245185     L3_CS_Run_Event  168752  1c28       0    0    4206003181232244864 
1114113     L3_CS_Run_Event  168432  1bd8       0    0    4205557536032244860 
1179649     L3_CS_Run_Event   96088  1a88       0    0    42057672520 9438312 
1179649     L3_CS_Run_Event   96384  1ed0       0    07444993267896040     744 
 
++++ Dumped message when csl was stopped without problems ++++ 
 
 type         buffer type  length strms  format part    run  evtnum section 
------------------------------------------------------------------------------ 
14751     L3_CS_Run_Event  116674    40   e0e00    0 238146    2878      40 
14751       L3_CS_Run_End     310     0   e0e00    0 238146       0     253 
</pre> 
CSL treated "No stream" events properly for several months. Partion 14 is safe.  
</li> 
<li> Those gray level3 farm turned to be broken between end of run and partition of next run, and were excluded from run. This never happened before(by l3 expert) and they investigate the reason. Serial failure of L3 farm and csl logger queues filling up is still there.   
</li>  
<li> Temporary solution is to clean up level3 farm every end of run.  
</li> 
<li> Check Willis' email for more detailed description 
<ul> 
<pre> 
Willis' email 
 
   Geum Bong and I spent a large part of this evening in the 
control room with Khaldoun (EVB/L3 farm) trying to understand 
this max-client issue. What we found is that there is an 
unusual interaction between the L3 farms and the CSL. 
   After CSL and L3 cleanup, the first run can be taken without 
problems. However, when you start a second run, that is, 
do an end run and re-partition, a problem occurs. You can tell 
there is a problem by looking at the L3 farm display in the 
control room. About 70% of the L3 farm nodes will be gray 
(inactive) while the rest is taking data. In this situation, 
a fraction of the events that the CSL gets appears to be 
corrupted. The csl_receiver puts them into the logger queue, 
but nothing takes them out. So, data taking will continue 
for a while until the logger queue fills up and stops 
accepting events from the EVB/L3 farms. This causes the EVB 
to pull a timeout, and the shift crew will then try to 
end the run and restart a new one. When they try to start a new 
run, the max-clients problem occurs. 
    So, the current solution is the following. When a run is 
ended, the L3 farms should be cleaned up. If cslMon says there 
are too many events in the logger queue, the CSL should be 
restarted first, and then L3 cleaned up. 
                                                 -- Willis 
 
</pre> 
</ul> 
</li> 
</ol>
<!-- Author: Geumbong -->
<!-- Comment: Wed Jul 25 21;28;11 comment by...Geumbong -->
<b><font color=red><big> PROBLEM SOLVED </big></font></b> <br><a href="
http://www-cdfonline.fnal.gov/cgi/elog/elog.pl?nb=2007&action=view&page=618&frame=2&anchor=18:07:53.602"> Check shift e-log entry</a>



<!-- Date: Wed Aug 1 13:01:18 2007 -->
<pre>Open files in b0csl26 
 
54:b0csl26 % Edm_EventLister er03bf8b.0001phys 
55:b0csl26 % Edm_ObjectLister er03bf8b.0001phys 
 CHKLOG: BFIELDM logical translation: /cdf/onln/code/cdfsoft/dist/packages/GeometryBase/V00-00-87/src/bfieldmap.dbt 
 Bfield::print: nominal magnetic field is:     14.116;  field is  NON-UNIFORM 
</pre>
<!-- Author: Geumbong -->


<!-- Date: Tue Aug 7 10:31:04 2007 -->
<pre>The lost connection issue between L3 and CSL happened at Aug. 6th after shutdown. 
We found some ports of the switches (L3-CSL and Data) turned off. 
After we restarted these ports several times and exchanged related LAN cables, 
we concluded it was not cable issue. 
In fact one of the cause was not serious...just unplugged/unused cable 
(although we should label it later). 
But the others were due to lost configuration of the L3-CSL switch.  
Actually the spare Data switch also lost its configuration. 
Tatsuya and Willis pointed it out and started to recover the L3-CSL switch. 
After Tatsuya reconfigured network setting of the switch with web interface 
(We failed to login via serial console),  
he logged on it and copied & pasted the configuration on the CSL web page. 
Finally CSL was recovered, but we still don't know why we lost the configuration during shutdown.</pre>
<!-- Author: Hideki, Willis, Tatsuya, Yoshikazu -->


<!-- Date: Tue Aug 7 14:20:16 2007 -->
<pre>These are the summary of the status of CSL systems after power outage. 
 
-b0csl20 
The b0csl20 was rebooted after power outage. However, it did not success booting correctly because other systems (ex. Data1, ...) did not work (UPS problem). So, when we tried to log in to b0csl20, it was failed. 
 
-csl logger nodes 
The csl logger nodes were shutdowned during power outage. We are not sure csl logger nodes were correctly powered off or not. 
 
-UPS devices 
Some channels indicated green lamp (working), however, others showed nothing(UPS was not working). It seems UPS shows strange behavior. 
 
-Satabeast 
Satabeasts were also powered off during power outage. 
 
================================= 
What we did 
 
- We powered off b0csl20 by hand, then we restarted UPSs. 
 
- After all systems turned on, we try to recover systems by hand.(mounting disk1 and disk2) 
 
- The command to recover from power outage seems not working. 
Because next command needs password @cslace, however, we do not know it. 
 
"sudo /usr/local/sbin/startup.b0.sh" 
 
So, Recovering systems with this script seems currently impossible.  
</pre>
<!-- Author: Yoshikazu, Hideki -->


<!-- Date: Fri Aug 10 02:19:23 2007 -->
<pre>Now I'm in front of CSL rack. Almost all looks OK except b0csl29 and SWITCH...I regret I didn't update it... 
Anyway I turned b0csl29 on by hand and will recover the switch as following well known procedure.</pre>
<!-- Author: Hideki -->
<!-- Comment: Fri Aug 10 04;17;59 comment by...Hideki -->
<pre>Done. CSL-L3 and Data switches were reconfigured and could start with cold-boot command (reload). When I tried to start the CSL system, I found two loggers failed to mount the satabeast disks.
I rebooted them. One (b0csl23) was recovered but the other (b0csl25) still failed.
</pre>

<!-- Comment: Fri Aug 10 05;25;25 comment by...Hideki -->
<pre>Finally I exchanged the failed logger (b0csl25) with the spare logger (b0csl21). Now the CSL system seems to be working correctly. 
Old config files are backed up on /cdf/onln/home/cslace/logger.config.070117 and /cdf/onln/home/csl/csl_conf_temp/csl.conf.070420 .
I also requested for the Help Desk to mount correct partitions (Ticket #: 102397).</pre>

<!-- Comment: Mon Aug 13 19;21;35 comment by...Geumbong -->
<b><font color = magenta> B0csl25 is back </font></b>


<!-- Date: Wed Aug 15 15:07:03 2007 -->
<b> CSL_Max_Client_Error </b> happened over the night.  
<p> 
It was interesting to see this because the logger queues were full around 3:38 am, but it was seen by ace by 1pm. They took a couple of calibrations and l2 torture runs, which don't write out files. That's why it was seen way late from when it was really happening, <a href="http://www-cdfonline.fnal.gov/cgi/elog/elog.pl?nb=2007&action=view&page=674&scroll=false"> run 247079 summary </a>. According to the error log, L2 timeout error seemed to cause this problem. 
<!-- Author: Geumbong -->
<!-- Comment: Wed Aug 15 16;08;43 comment by...Geumbong -->
Comparing the number of events appeared in the error log with message queues, L2 timeout error happened after csl message was full. However, it's not clear why it happened. The events dumped in message queues are not in order.

<pre>
**** From csl dump out ****

 type         buffer type  length strms  format part    run  evtnum section
------------------------------------------------------------------------------
589825     L3_CS_Run_Event   92255   100   e0e00    0 247079  628726     717
589825     L3_CS_Run_Event   91551   100   e0e00    0 247079  628352     717
589825     L3_CS_Run_Event   91619   100   e0e00    0 247079  628127     717
589825     L3_CS_Run_Event   92204   100   e0e00    0 247079  628373     717
589825     L3_CS_Run_Event   92091   100   e0e00    0 247079  629234     717

*** From error logger ****

CT: 2007.08.15 03:38:15
38'15" b0tsi00:Messenger:Aug 15, 2007 03:38:16 AM->TM2 Timeout waiting for pending events from HEVB2b, partition 0, lastEvent 633465 -->  
 Additional Information: 

 Attention !!!. FERML_TM2_HEVB2B_EVENTS_PENDING_TIMEOUT !!! 
 - AUTO HRR will be issued.  
 - If problem persists, please use the DiagnoseTO button  
   on the EVB Ace Control Panel. 
[MLE]
</pre>

<!-- Comment: Wed Aug 15 17;10;20 comment by...Geumbong -->
It seems <b><font color=purple>Open file</font></b> problem.
<pre>
From b0csl28 log files.. 


[00i] New file opened: /mnt/data1/logger/ace/00/.open/ir03c527.02cecosm
[00i] File closed: /mnt/data1/logger/ace/00/ir03c527.02bacosm
[00i] [9561 events; 971395208 bytes:written; 972641723 bytes:filesize; 1 MB/s]
[00i] DB file written: /mnt/data1/logger/ace/00/ir03c527.02bacosm.db [RS min = 698 max = 708]
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/ir03c527.02cecosm already exists

--------------------------------------------------------------------------------
ERROR--> hostname: b0csl28.fnal.gov
         prg name: $Id: csl_logger_client.c,v 1.9 2007/06/05 18:31:17 richard Exp $
         function: csl_logger_openfile()
         datetime: Wed Aug 15 03:38:01 2007
         src file: /cdf/onln/code/cdfprod/csl/v2_8/src/programs/csl_logger_client.c
         src line: 1468
         src info: [00i] Error opening output file: ir03c527.02cecosm
         sys perr: File exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/ir03c527.02cecosm already exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/ir03c527.02cecosm already exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/ir03c527.02cecosm already exists
Error in <TFile::TFile>: file /mnt/data1/logger/ace/00/.open/ir03c527.02cecosm already exists
SIGQUIT caught! Exiting logger client child.


 *** Break *** write on a pipe with no one to read it
[00i] csl_logger_child_send_out exiting...
</pre>

<!-- Comment: Wed Aug 15 17;28;13 comment by...Geumbong -->
By looking at the log file, the file was opened once and logger tried to open it after closing other file, kind of timing issue. One interesting thing is that it happened after spliting file. There seems a confliction between treating split file and open a new file. The open file was null file. 
<pre>
72:b0csl28 % cd .open
73:b0csl28 % lsr
total 4.0K
-rw-r--r--  1 cslace cdf 306 Aug 15 03:38 ir03c527.02cecosm
</pre>


<!-- Date: Mon Aug 20 19:17:17 2007 -->
<p>The main CSL version has been updated to v2_9, which is now 
the default. The changes have been to the csl_logger. 
<ul> 
<li>csl_logger.c: Added valid stream checking to prevent 
    events being put back into the logger message queue that 
    are typed for non-existant streams. These get stuck.</li> 
<li>csl_logger_client.c: Modified open file handling function. 
    Oversized files are first closed before processing the 
    current event. If an oversized is the newer file, and the 
    current event belongs in it, a split file is generated.  
    Events are rejected if their run section 
    is under the oldest file&#39;s lower run section limit, 
    or between the run section limits of the older and 
    newer open files. The following policy is being enforced:  
    Only the upper run section limit of the newer file can 
    be extended, and only a maximum of two open files are 
    allowed.</li> 
</ul> 
</p>
<!-- Author: Geum Bong, Willis -->