<!-- Title: 19:39:14  Wed Aug 18 1999 -->
<!-- Crewchief: Christoph Paus -->
<!-- Op1: Jeff Tseng -->
<!-- Op2: Ilya Kravchenko -->
<!-- Op3: Steve Tether -->
<!-- Op4: Andreas Korn -->
<!-- Op5: Michael Mulhearn -->
<!-- Op6: Ivan Furic -->
<!-- Notes: -->
<FONT COLOR="#FF0000"> 
<P> 
Today the new 28 PCs arrived at Fermilab which are the hardware required to build up the Level-3 engineering system. 
</P> 
</FONT> 
 
<P> 
Reason enough to start a new Level-3 Logbook File. 
</P>


<!-- Date: Fri Aug 20 00:13:14 1999 -->
This might be useful as a reference. 
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% 
%%%%%%%%%                                       %%%%%%%%%% 
%%%%%%%%%              RAW EVENT                %%%%%%%%%% 
%%%%%%%%%                                       %%%%%%%%%% 
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% 
 
  An explanations of all words in raw event from 
the wedge taken on Aug. 19, 1999. Consists of 1 SCPU, 
1 VRB with only 1 link. 
 
 6b6b1919	Sender ID                                         -------- 
      1f0	Message length                                     Message 
 1f56be00	Message type                                       header 
 33fafb00	Receiver ID                                       -------- 
 
 6c010000	Event length in bytes 
 
 68010000	SCPU length in bytes                              -------- 
  1000000	?                                                  SCPU 
 21000000	? some SCPU information,                           header 
 43000012	? not used by reformatter                          section 
 70380055	? at the moment                                    
 76635f6d	?                                                 -------- 
 
        0	VRB byte count = 0 __\ 64 bit                     -------- 
 50010000	VRB byte count       /  word                         
        0       status of VRB                                       VRB  
        0       \     Pointer section I*2 of VRB (link length)     header 
        0        \  Total are 10 links. Here we see the last       section 
        0         | 10th link is not 0, byteswap(3001)=>130=>4c,    
        0        /  as seen in the next word.                        
 30010000       /                                                 -------- 
 
 4c000000	Number of words in current link                   -------- 
                                                                   | 
 444d4543	Bank name CEMD                                     |  ---- 
  1000000	Bank number (0xuuuullll), where uuuu - total       |   | 
                   number  of banks and llll - instance            |   | 
        0	Bank next (for raw data always 0 as no two         |  Bank  
                   versions of a bank                              |   | 
 15000000	Bank length in words (32bits). Starts at 0 for     |  header 
		   this word                                       |   | 
  3000000       Bank type (1=I*2, 3=I*4, 4=R*4)                    |  ---- 
 2c004005 2e004105 2b004205 2b004305  \                            | 
 30004405 32004505 2f004605 33004705   \                           | 
 2d004805 2e004905 2e004a05 2d004b05    |  Data                    |  Data 
 31004c05 2e004d05 2c004e05 2e004f05   /                           |   
 2d005005 2b005105 2f005205 30005305  /                            |  
                                                                   |  ---- 
 44414843	Bank name CHAD                                     |   | 
  1000000                                                          |  Bank 
        0       Bank header is the same as above                   |  header 
 29000000                                                          |   | 
  3000000                                                          |  ---- 
 27004005 36004105 2c004205 2a004305 2e004405 2d004505 \           | 
 31004605 2f004705 31004805 3f004905 2c004a05 1d004b05  \         Link 
 36004c05 34004d05 30004e05 2c004f05 32005005 29005105   |         |    
 30005205 26005305 2d008005 30008105 2f008205 30008305   | Data    |  Data 
 2c008405 34008505 2d008605 2f008705 2c008805 31008905   |         | 
 2c008a05 2f008b05 2b008c05 2d008d05 2c008e05 2e008f05  /          | 
 33009005 31009105 32009205 31009305                   /           | 
                                                                   |  --- 
        0       < Control word 0                                   | 
 aaaaaaaa       < Control word A                                   | Link 
 55555555       < Control word 5                                   | control 
  2011700       < Tracer word (not checked by reformatter          | words 
       80       < End of data word                                 | 
        0       < possible pad word, for 64 bit alignment         -------  
<!-- Author: Ilya Kravchenko -->
<!-- Comment: Fri Aug 20 18;01;59 comment by...Ilya Kravchenko -->
Sorry, my netscape crashed at this point. Will try again.


<!-- Date: Fri Aug 20 18:04:19 1999 -->
<pre>%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% 
%%%%%%%%%                                       %%%%%%%%%% 
%%%%%%%%%              RAW EVENT                %%%%%%%%%% 
%%%%%%%%%                                       %%%%%%%%%% 
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% 
 
  This is an explanations of all words in raw event from 
the wedge taken on Aug. 19, 1999. Consists of 1 SCPU, 
1 VRB with only 1 link. 
 
 6b6b1919	Sender ID                                         -------- 
      1f0	Message length                                     Message 
 1f56be00	Message type                                       header 
 33fafb00	Receiver ID                                       -------- 
 
 6c010000	Event length in bytes 
 
 68010000	SCPU length in bytes                              -------- 
  1000000	?                                                  SCPU 
 21000000	? some SCPU information,                           header 
 43000012	? not used by reformatter                          section 
 70380055	? at the moment                                    
 76635f6d	?                                                 -------- 
 
        0	VRB byte count = 0 __\ 64 bit                     -------- 
 50010000	VRB byte count       /  word                         
        0       status of VRB                                       VRB  
        0       \     Pointer section I*2 of VRB (link length)     header 
        0        \  Total are 10 links. Here we see the last       section 
        0         | 10th link is not 0, byteswap(3001)=>130=>4c,    
        0        /  as seen in the next word.                        
 30010000       /                                                 -------- 
 
 4c000000	Number of words in current link                   -------- 
                                                                   | 
 444d4543	Bank name CEMD                                     |  ---- 
  1000000	Bank number (0xuuuullll), where uuuu - total       |   | 
                   number  of banks and llll - instance            |   | 
        0	Bank next (for raw data always 0 as no two         |  Bank  
                   versions of a bank                              |   | 
 15000000	Bank length in words (32bits). Starts at 0 for     |  header 
		   this word                                       |   | 
  3000000       Bank type (1=I*2, 3=I*4, 4=R*4)                    |  ---- 
 2c004005 2e004105 2b004205 2b004305  \                            | 
 30004405 32004505 2f004605 33004705   \                           | 
 2d004805 2e004905 2e004a05 2d004b05    |  Data                    |  Data 
 31004c05 2e004d05 2c004e05 2e004f05   /                           |   
 2d005005 2b005105 2f005205 30005305  /                            |  
                                                                   |  ---- 
 44414843	Bank name CHAD                                     |   | 
  1000000                                                          |  Bank 
        0       Bank header is the same as above                   |  header 
 29000000                                                          |   | 
  3000000                                                          |  ---- 
 27004005 36004105 2c004205 2a004305 2e004405 2d004505 \           | 
 31004605 2f004705 31004805 3f004905 2c004a05 1d004b05  \         Link 
 36004c05 34004d05 30004e05 2c004f05 32005005 29005105   |         |    
 30005205 26005305 2d008005 30008105 2f008205 30008305   | Data    |  Data 
 2c008405 34008505 2d008605 2f008705 2c008805 31008905   |         | 
 2c008a05 2f008b05 2b008c05 2d008d05 2c008e05 2e008f05  /          | 
 33009005 31009105 32009205 31009305                   /           | 
                                                                   |  --- 
        0       < Control word 0                                   | 
 aaaaaaaa       < Control word A                                   | Link 
 55555555       < Control word 5                                   | control 
  2011700       < Tracer word (not checked by reformatter          | words 
       80       < End of data word                                 | 
        0       < possible pad word, for 64 bit alignment         ------- 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Sun Sep 19 23:45:00 1999 -->
<pre>Performance measurements. This time we go to up to 15 SCPUs. 
There are ATM driver updates, new ATM switch and software, etc. 
 
System configuration: 
 
  NSCPU->1CV-> trash, n=188 (1 MB/s/SCPU), fragment 
size 12kB with sigma 4, UNCORRELATED. Timeout settings: 
l3_tries = 2000, l3_wait = 15. Number of builders is 3. 
 
          rate, ev/s  Nev in sample    throughput, MB/s 
                       (good/bad) 
  1 SCPU   86.8+-0.2   30649/1           1.0+-0.02 
  3 SCPU   86.7+-0.2   30316/0           3.0+-0.06 
  5 SCPU   86.4+-0.1   93946/1           5.1+-0.05 
  7 SCPU   86.3+-0.1   51769/1           7.1+-0.07 
  9 SCPU   86.2+-0.1   51623/0           9.1+-0.09 
 12 SCPU   85.9+-0.1   50469/0          12.1+-0.12 
 14 SCPU   86.0+-0.1   60303/1          14.1+-0.14 
 15 SCPU   dies in 5-10,000 ev, rate ok 
 
 
 
  NSCPU->1CV->4proc->1OUT->trash, n=188 (1 MB/s/SCPU), fragment 
size 12kB with sigma 4, uncorrelated. Timeout settings: 
l3_tries = 2000, l3_wait = 15. Number of builders is 3. 
                                          
  1 SCPU   82.7+-0.1  52575/1           0.97+-0.01 
  3 SCPU   82.0+-0.1  54436/1           2.88+-0.01 
  5 SCPU   80.3+-0.1  53747/0           4.71+-0.01 
  7 SCPU   79.0+-0.4  58316/0           6.48+-0.03 
  9 SCPU   75.9+-0.7  58982/0           8.01+-0.07 
 12 SCPU   73.1+-1.0  55759/0          10.28+-0.14 
 14 SCPU   71.7+-1.2  60702/0          11.76+-0.20 
 15 SCPU   dies in 5-10,000 ev 
 
Comments:  
 - in all cases bad event is the first event 
 - I have saved rate vs time dependence, it does 
    not exibit periodic drop in rate as it used 
    to happen. Rather, the rate appears to fluctuate 
    randomly 
 - I was puzzled by the fact that for 15 SCPU 
    the system eventially dies, but then I realized 
    that 15SCPU*1MB/s/SCPU is 15MB/s so we are 
    ethernet-limited.</pre>
<!-- Author: Ilya Kravchenko -->
<!-- Comment: Mon Sep 20 09;42;14 comment by...Steve -->
The converter node dies with 15 SCPUs even when writing to trash, so it can't just be a matter of ethernet bandwidth. Even if it were, the throughput in MB/s should just reach a plateau without a program crash. This looks like a software problem, perhaps a memory leak that gets worse the more SCPUs you use.


<!-- Date: Sun Sep 26 22:18:40 1999 -->
<pre>Log of the tests done around Sept 15 - Sept 25. 
We test a large system, more converters, more SCPUs, 
larger ATM switch.  
 
 
Test conditions: 
---------------- 
 
  NSCPU->MCV-> trash, n=188 (1 MB/s/SCPU), fragment 
size 12kB with sigma 4, UNCORRELATED. Timeout settings: 
l3_tries = 2000, l3_wait = 15. Number of builders is 3. 
 
  Test with 1 converter 
  --------------------------------------------- 
This (1 converter test) is taken on the early stage, there were  
soft and hardware rearrangemenrs after. 
          rate, ev/s  Nev in sample    throughput, MB/s 
                       (good/bad) 
  1 SCPU   86.8+-0.2   30649/1           1.0+-0.02 
  3 SCPU   86.7+-0.2   30316/0           3.0+-0.06 
  5 SCPU   86.4+-0.1   93946/1           5.1+-0.05 
  7 SCPU   86.3+-0.1   51769/1           7.1+-0.07 
  9 SCPU   86.2+-0.1   51623/0           9.1+-0.09 
 12 SCPU   85.9+-0.1   50469/0          12.1+-0.12 
 14 SCPU   86.0+-0.1   60303/1          14.1+-0.14 
 
Now newer results: 
  1 SCPU   86.8+-0.1   10000              1.02+-0.01 
 14 SCPU   85.7+-0.2   20000             14.06+-0.03  
 
  Test with 2 converter 
  --------------------------------------------- 
   14 SCPU  79.51+-0.08          50000              13.04+-0.01 
   14 SCPU  79.43+-0.10          10000 (this is just a check) 
Now, try again with 2 converters but 0 sigma of fragment size 
   14 SCPU  87.21+-0.20   
Next, sigma=4k and the fragments are correlated 
   14 SCPU  85.6+-0.12 
Next, sigma is 4k and random number is generated, but mean is returned 
   14 SCPU  87.2+-0.02 
 
  Test with 3 converter 
  --------------------------------------------- 
   14 SCPU  78.35+-0.05          50000              12.85+-0.01 
 
  Test with 4 converters 
  --------------------------------------------- 
          rate, ev/s/conv  Nev in sample          Throughput, MB/s 
                             per converter         per converter 
    1 SCPU  85.1+-0.1          ~700000               1.00+-0.001 
    3 SCPU  82.5+-0.1           ~50000               1.93+-0.002 
    5 SCPU  80.2+-0.1            50000               4.70+-0.005 
 
    7 SCPU  80.01+-0.05          50000               6.56+-0.007 
   14 SCPU  77.08+-0.06          50000              12.65+-0.010 
   
  Test with 5 converters (c02-c05, c08) 
  ---------------------------------------------- 
              rate, ev/s/converter     N ev/converter 
 
This is I believe with sigma=0 fragments, also taken on 
the early stage. On the second thought, possibhly not. 
      1 SCPU     83.71+-0.04             ~200000     0.98+-0.001  
     14 SCPU     80.92+-0.03             ~180000    13.28+-0.005  
These are newer results with uncorrelated fragments 
      1 SCPU     84.1+-0.09                 short 
     14 SCPU     75.66+-0.06               50000    12.41+-0.01 
 
  Test with 6 converters (c01-c05, c08) 
  ---------------------------------------------- 
     14 SCPU     74.00+-0.04              ~50000    12.14+-0.004 
 
  Test with 7 converters (c01-c05, c08, c011) 
  ---------------------------------------------- 
      1 SCPU     81.49+-0.04              ~50000     0.95+-0.001     
     14 SCPU     70.68+-0.03          ~3,800,000    11.60+-0.005 
 
Long test with 14->7 system: 
   events recorded 
     b0l3c01           3852282/1 
     b0l3c02           3853080/10 
     b0l3c03           3865230/0 
     b0l3c04           3857201/0 
     b0l3c05           3864311/5 
     b0l3c08           3849069/1 
     b0l3c11           3844189/1 
   time  ~15 hrs 
   log files dated Sept. 23, 12:51 
   test stopped by hand 
 
   Test with 8 converters (c01-c05, c08, c09, c11) 
   ----------------------------------------------- 
 
      1 SCPU     79.36+-0.04                ~50000    0.93+-0.001  
     14 SCPU     68.77+-0.1             ~1,380,000   11.28+-0.016 
 
 
 
 
Now, a couple of summary tables made out of the above: 
------------------------------------------------------ 
  1. One SCPU sending to N converters 
      N conv          Rate, ev/s/conv       throughput, MB/s/conv   
        1               86.8+-0.2              1.0+-0.02 
        4               85.1+-0.1              1.00+-0.01 
        5               83.7+-0.1              0.98+-0.01 
        7               81.5+-0.1              0.95+-0.01 
        8               79.4+-0.1              0.93+-0.01            
 
  2. 14 SCPU sending to N converters: 
      N conv          Rate, ev/s/conv       throughput, MB/s/conv   
        1                86.00+-0.10            14.10+-0.14  
        2                79.51+-0.08            13.04+-0.01 
        3                78.35+-0.05            12.85+-0.01 
        4                77.08+-0.06            12.65+-0.01 
        5                80.92+-0.03            13.28+-0.01  (0 sigma)  
        5                75.66+-0.06            12.41+-0.01      
        6                74.00+-0.04            12.14+-0.01             
        7                70.68+-0.03            11.60+-0.01  
        8                68.87+-0.10            11.28+-0.02 
 
14->8 system remeasured with 'truly' uncorrelated fragments 
is 65.9+-0.1 ev/s.           
 
----------------------------------------------------------------- 
 
Now I will run a set of short plot-oriented tests 
with event fragments fixed in size to 12k. Samples 
for each easurement are about 15000 events. 
 
  14 SCPU 
      N conv           Rate                throughput 
       1             87.07+-0.07 
       2             87.19+-0.02 
       4             87.15+-0.03 
       6             87.00+-0.02 
       7             85.07+-0.3 
       8             77.38+-0.02 
 
------------------------------------------------- 
 
 More tests. This time we increase event fragments to 16kB. 
Also, uncorrelated fragments are 'more' uncorrelated by 
setting random seed for each SCPU. 
                       Rate, ev/s/conv       throughput, MB/s/conv 
  14 SCPU, variable fragments 
    1 conv             59.53+-0.08             13.02+-0.02 
    2 conv             59.07+-0.09             12.92+-0.02 
    4 conv             57.86+-0.03             12.66+-0.01 
    6 conv             56.03+-0.02             12.26+-0.01 
    8 conv             53.22+-0.01             11.64+-0.01 
 
  Make a plot with fixed size 16k fragments, 14 SCPU 
    1 conv             65.91+-0.03             14.42+-0.01 
    2 conv             65.94+-0.01             14.42+-0.01 
    3 conv             65.94+-0.04             14.42+-0.01 
    4 conv             65.33+-0.50             14.29+-0.11 
    5 conv             65.88+-0.04             14.41+-0.01 
    6 conv             65.80+-0.06             14.39+-0.01 
    7 conv             65.00+-0.50             14.22+-0.11 
    8 conv             59.58+-0.10             13.03+-0.02 
 
  Variable size fragments, 1 converter 
    1 SCPU             65.89+-0.13              1.03+-0.01 
    2 SCPU             63.71+-0.10              1.99+-0.01 
    4 SCPU             62.03+-0.08              3.88+-0.01 
    6 SCPU             61.14+-0.09              5.73+-0.01 
    8 SCPU             60.52+-0.07              7.57+-0.01 
   10 SCPU             60.08+-0.06              9.39+-0.01 
   12 SCPU             59.77+-0.07             11.21+-0.02 
   14 SCPU             59.53+-0.08             13.02+-0.02 
 
  Fixed size fragments, 1 converter 
    2 SCPU             65.94+-0.04              2.06+-0.01 
    4 SCPU             65.95+-0.02              4.12+-0.01 
    6 SCPU             65.94+-0.02              6.18+-0.01 
    8 SCPU             65.93+-0.01              8.24+-0.01 
   10 SCPU             65.93+-0.01             10.30+-0.01 
   12 SCPU             65.94+-0.02             12.36+-0.01 
   14 SCPU             65.91+-0.03             14.42+-0.01 
 
  For the following test we also include a subfarm: 
   Nscpu->1cv->4proc->1out->trash. size=16k+-4/frag., 
   Processor nodes reject 90%. Variable size fragments 
    1 SCPU             65.46+-0.13              1.02+-0.01 
    2 SCPU             62.77+-0.08              1.96+-0.01 
    4 SCPU             60.59+-0.09              3.79+-0.01 
    6 SCPU             59.14+-0.24              5.54+-0.02 
    8 SCPU             57.21+-0.47              7.15+-0.06 
   10 SCPU             57.61+-0.29              9.00+-0.05 
   12 SCPU             55.87+-0.86             10.48+-0.16 
   14 SCPU             56.02+-1.00             12.25+-0.21 
 
   Also, the same as above but fixed 16k fragments 
    1 SCPU             65.98+-0.02              1.03+-0.01 
    2 SCPU             65.91+-0.07              2.06+-0.01 
    4 SCPU             65.38+-0.33              4.09+-0.02 
    6 SCPU             65.22+-0.76              6.11+-0.07 
    8 SCPU             62.83+-1.17              7.85+-0.15 
   10 SCPU             64.88+-1.07             10.14+-0.17 
   12 SCPU             62.32+-1.09             11.69+-0.20 
   14 SCPU             61.38+-1.63             13.43+-0.36 
  
  Comment: - in the last 2 tables periodical drops in event 
    rate are observed. This in particular is indicated by 
    larger errors on the rate (the sample sizes are about 
    the same in most of the ebove tests).  
      - In the last table event rate is reduced because of 
    these periodical drops only, most of the time it stays 
    very close to 66 Hz. 
      - in the last 2 tables rows for SCPU=4,8,12 are taken 
    in a day after the others. They are slightly different. 
 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Tue Oct 19 11:13:22 1999 -->
b0l3pcom1 has been upgraded to a new machine. 
The disk with /home has been moved into the new PC. 
The directory /usr/products was copied. 
In order to get ups work, I had to do an rather ugly  
hack to change /fnal/ups/etc/setup* to old files (/usr/local/etc).
<!-- Author: Andreas Korn -->


<!-- Date: Tue Oct 19 22:08:31 1999 -->
<pre>add c++ compiler files for development on b0l3pcom1. 
 
egcs-1.0.3a-14.i386.rpm (needs --force) 
egcs-c++-1.0.3a-14.i386.rpm 
libg++-devel-2.7.2.8-6.i386.rpm  
libstdc++-devel-2.8.0-14.i386.rpm (needs --nodeps -i) 
</pre>
<!-- Author: Andreas Korn -->


<!-- Date: Wed Oct 20 21:31:26 1999 -->
<pre> Today we had some progress in running DAQ on real data, 
Steve Tether, Fkw, Jeff were around control room this afternoon. 
 
 - We can now reformat all kinds of banks successfully. 
Christoph has a modified reformatter and so do I.  
 
 - We sent data from 3 crates (2 TDC crates and central calorimeter 
crate, also Shower Max included somewhere here) to 1 DAQ crate 
that has 1 SCPU and 1 VRB with 3 active links. Then we go to 
1 converter, 1 processor (that has reformatter and Kevin's executable), 
1 output, then it goes to the CS/DL where it is saved to TRYBOS 
file and also sent to the consumer. This whole chain worked well. 
Various little bugs in all components were fixed along the way. 
The event rate was about 200 Hz (input to level3) and event 
size around 2kB. 
 
 - I have saved a little of data, but probably we will be too busy 
with other things to look at them. 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Tue Oct 26 00:42:08 1999 -->
<pre>In the data below we were running on real VRB with 2 TDC crates 
and one CCAL crate. 
 
 Here are some performance measurements. Inspired mainly by Frank Chlebana. 
I will also put this into level3 e-log. 
 
Fake data. I wanted to find the limit on the maximum event rate. 
 I observed 300 Hz per converter some time ago, but now it is a little less. 
 This test is done on a simple system of 1 SCPU sending to 1 converter to trash. 
 
Event size,   Event rate,       Throughput 
  bytes        ev/sec             MB/sec 
 1560         270.8+-1.20          412.5 
 3072         257.6+-0.91          772.8 
 4608         203.6+-0.77          916.2 
 6144         168.0+-0.16         1008.0  
12288          87.2+-0.03         1046.4 
 
Real data. In configuration 1 SCPU-> 1 converter -> trash 
the rate is 276 Hz at fragment size 1560 byte, close to the fake  
data result. 
  By reading out just VRB without the full event builder, we observe 
the rate of approx. 1.1kHz 
 
  Next, tests with a full subfarm containing different number of processor  
nodes (each is running 2 instances of L3 executable). The system now is: 
   (detector)-> 1 SCPU -> 1 converter -> N processors -> 1 output ->trash 
[the output node is b0l3021 here] 
The expected behaviour is 50Hz per processor node until reaches the upper  
limit of 300 Hz (limit per converter) or limit of how much data can be  
provided for readout (according to Frank Ch., impossible) 
 Number of    Real data 
processors    event rate 
   1          49.9+-0.04 
   2          99.9+-0.04 
   3         146.2+-2.20 
   4         172.8+-1.5 
   5         173.9+-1.78 
   6         171.4+-1.10 
 
  So, the event rate scales with the number of processors only up to some point. 
Several more tests with 1 subfarm containing 5 processor nodes: 
 
  Sending fake data, 1560b size.                           170.8+-1.5 Hz 
  Fake data. Use real output node (b0l3u01).               175.2+-2.6 Hz 
 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Tue Oct 26 23:36:32 1999 -->
<pre>  Some progress of today (Petar, myself and Frank W): 
 
 - we have reproduced a test with one and two SVX crates 
 with no reformatting. Auto-SRC trigger for SVX (i.e., not 'real'). 
 
 - reformatter: I have recompiled my level3 with Christoph's 
reformatter. The reformatting on a system 
 SVX DAM/FIB -> 1SCPU/1VRB->1 converter->1processor->1output 
was ok. No warnings that I had with my reformatter. 
When we tried 2 SCPUs, each reading out 1 VRB, we got complains 
from reformatter: 
>    == ERROR rr_refevt_bank_add_mini ==  
> 
>  bank instance: 1 fragment instance: 1 
>  mini fragment appeared with ambiguous instance 
>  mini fragment not added to bank 
>  >>EXIT  rr_refevt_bank_add_mini 
> 
there is still some output produced and nothing crashes. 
I will also need to try Christoph's reformatter on TDC/ADMEM data. 
 
 - we sat down and went through raw data file trying to understand every 
byte. Here is the result. Can experts comment on the beginning of 
the event record? What does everybyte mean there? I do not see 
standard 6 SCPU header words. The 4 event header words seem to be in place. 
Also, note, that this raw event data file was saved on PC/Linux 
then ftp'ed to b0dau30 and octal-dumped. So beware of byteswaps. 
 
----------------------------------------------------- 
  RAW DATA FROM SVX 
----------------------------------------------------- 
0000000 0000 0c5c 0000 0c58 0000 0001 0000 0021    Four double words of event  
header ? 
0000020 5f68 0000 7200 0073 3300 2300              THIS PART I DO NOT  
UNDERSTAND. 
                                                        Please, help. 
 
                                                  VRB HEADER 
 
                                      0c40         Total bytecount 3136 
                                           0006      00 - time since last L1  
accept 
                                                     06 - event ID from TS 
 
0000040 0010 0004 0400 4000                        VRB channel status in funny 
                                                   format (in chunks of 6 bits) 
 
                            0c1e 0000 0000 0000    VRB byte count, by channel 
0000060 0000 0000 0000 0000 0000 0000              (16 bits per channel) 
 
                                                   FIB HEADER 
 
                                      e0           Port Card A id 
                                        0          Port Card B id 
                                         0         Fib channel number 
                                           00      Bunch Crossing number 
                                             fc    ?? (last two bits are  
"Dr.Q", 
                                                   Digitize/Readout/Quiescent 
                                                   -- Back-End state of the  
SVX chip, 
                                                   as emulated by SRC) 
 
                                                  CHIP DATA 
 
0000100 8b80                                      Beginning of the chip ID=b 
             007e 017d 027c 037b 047a 0579 0678     Data section. For example,  
0000120 0777 0876 0975 0a74 0b73 0c72 0d71 0e70     007e means channel = 00,  
0000140 0f6f 106e 116d 126c 136b 146a 1569 1668     content = 7e, and so forth. 
0000160 1767 1866 1965 1a64 1b63 1c62 1d61 1e60 
0000200 1f5f 205e 215d 225c 235b 245a 2559 2658 
0000220 2757 2856 2955 2a54 2b53 2c52 2d51 2e50      
............................................... 
0000460 7707 7806 7905 7a04 7b03 7c02 7d01 7e00 
0000500 7f7f  
             8a80                                Beginning of the chip ID=a 
                  007e 017d 027c 037b 047a 0579 
0000520 0678 0777 0876 0975 0a74 0b73 0c72 0d71 
0000540 0e70 0f6f 106e 116d 126c 136b 146a 1569     Data 
0000560 1668 1767 1866 1965 1a64 1b63 1c62 1d61 
0000600 1e60 1f5f 205e 215d 225c 235b 245a 2559 
............................................... 
0001040 6e10 6f0f 700e 710d 720c 730b 740a 7509 
0001060 7608 7707 7806 7905 7a04 7b03 7c02 7d01 
0001100 7e00 7f7f  
             8980 
                  007e 017d 027c 037b 047a 
..................................... 
..................................... 
 
0006060 6c12 6d11 6e10 6f0f 700e 710d 720c 730b 
0006100 740a 7509 7608 7707 7806 7905 7a04 7b03 
0006120 7c02 7d01 7e00 7f7f 
                            c1c1 0000                End of the event 
 
 
 
 
 
-------------------------------------------------------------------------- 
 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Fri Oct 29 14:09:08 1999 -->
<pre>Work around to get daqmsg setup on b0l3pcom1. 
Handmade a jdk ups product from java as daqmsg needs jdk.</pre>
<!-- Author: Andreas Korn -->


<!-- Date: Fri Oct 29 19:13:23 1999 -->
<pre> 
 This is the octal dump of a raw event saved on the converter node - SVX data. With  
explanations coming from Jeff and Petar. It is similar to the one put in e-log a 
couple of days ago, only a bit rearranged and with more explanations. 
Beware of byteswap(?). 
  Note that the data file contain no event header with "Sender ID", "Receiver ID", etc., 
and no SCPU header words because we look at the dump of a disk file.  
Instead, format is the following:  
 
00000c5c              Length of the disk record of an event, inclusive (3164 bytes) 
                   Beginning of the first fragment (i.e., data from 1 SCPU): 
00000c58            Length of fragment in bytes (3158 bytes)                
00000001            Number of VRBs in this fragment 
00000021            Event builder tag word (partition 1, tag 1) 
 
5f680000            These three are pad words and contain no information 
72000073  
33002300  
 
 
                                                  VRB HEADER 
 
0c400006            0c40-Total bytecount 3136, 00 - time since last L1 accept 
                                           06 - event ID from TS 
 
00100004            VRB channel status in funny  
04004000                         format (in chunks of 6 bits) 
						   
0c1e0000            VRB byte count, by channel  
00000000              (16 bits per channel) 
00000000  
00000000  
00000000 
 
                                                   FIB HEADER 
e00000fc           e0 - Port Card A id 
                    0 - Port Card B id 
                    0 - Fib channel number 
                   00 - Bunch Crossing number 
                   fc - ?? (last two bits are "Dr.Q", Digitize/Readout/Quiescent 
                           -- Back-End state of the SVX chip, as emulated by SRC) 
 
						  CHIP DATA 
 
8b80007e          8b80 - Beginning of the chip ID=b 
                  007e - channel 00, data content - 7e 
017d027c          channels 01 and 02   
037b047a             ...  
05790678       
  ...                ... 
7d017e00 
7f7f8a80          7f7f - channel 7f and data content (7f in this example) 
                  8a80 - Beginning of the chip ID=a 
007e017d          channels 00 and 01 (chan. ID and data)   
027c037b             ...  
047a0579             ... 
  ...                ... 
7e007f7f             ... 
c1c10000         c1c1 means  end of the event 
 
 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Sat Oct 30 19:09:54 1999 -->
<table><tr><td><a href=/elog/notebooks/l3/Sat_Oct_30_1999_190920.ps align=top><img src=/elog/gifs/ghost64.gif  width='56' align='top'></td><td>The plots of temperature mesurements. Shown is Board and Chip temperature for both CPU's. The CPU's where heated with a benchmark program and then let cool down. On Converters only 1 CPU could be heated.</a></td></tr></table>
<!-- Author: Andreas Korn -->


<!-- Date: Tue Nov 2 22:40:44 1999 -->
<pre>  Today we (Petar, Frank, Mako and many friends) tried to produce 
a core and log files of the L3 executable for Kevin to look at. 
A good news is that this time executable worked on SVX data. 
(Probably after Christoph's work last weekend). We were able to 
run with 2 VRBs from SVX and send data through reformatter, 
L3 executable to consumer server. In L3 executable I set random 
filter parameter to 1.0 (as far as I understand, only random filter 
lets SVX data pass when nothing else is present). 
 
  Interested people can find a file saved by CSL on b0dau31 
/logger/disk1/csl/991102220215.araw 
 
  One can dump this bank using Mako's executable 
~mako/testrel/bin/IRIX6-KCC_3_3/TRY_bank_hexdump 991102220215.araw 
(this dumps everything and recognizes SIXD) 
   or one can use Frank's 
~chlebana/bin/BNK_bank_dump 991102220215.araw 
   which appears to ignore SIXD, but does not crash and prints out 
a lot of LRIH and TL3B 
 
  In the near future, it would be good to confirm that null executable 
of level 3 does not produce the right kind of events and change it 
so that it does. (Or reformatter?) I guess I will have to look into it. 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Tue Nov 2 23:27:49 1999 -->
<pre> 
  Today we experienced some problems starting the system with the 
real links to TDC, CAL and SVX crates. We used to have problems 
every now and then before, but today was more difficult than usual  
for Evb/L3. I am sending this mostly to our experts, perhaps someone 
will have some input. 
 
1. System typically runs great with fake data. I do not remember 
any problems lately. 
 
2. With real data, if I start the run while run control has not 
started sending data yet (e.g., with a single TDC crate), as a rule 
I can not login (telnet) to SCPU. At this time "VME" light is always on  
on the VRB. Once the run is started, I can telnet without problems. 
Same situation happens when run control ends the run before EVB does. 
Steve seems to think that this should not happen. How can we find out 
what is wrong?  
 
3. Today we were having problems running with SVX.  
 - If we start SVX and read out data with stand-alone code of reformat_vrb 
on SCPU, it reads out successfully, no matter if SVX is setup  
in Auto-SRC trigger or with full TS - Run Control setup. 
 - A simple test with SVX triggering in Auto-SRC mode, sending data 
    through EVB to L3 with converter running to trash worked well 
 - But the test with the full Run Control and TS ->EVB->converter->trash 
   does not work. Later this evening we were able to start it with Petar 
   several times, but it would die shortly, in a couple of min. 
 Naively, one would think that there should be no difference for EVB/L3 
whether SVX is running in Auto-SRC mode or in full RC-TS setup since 
we are still not connected to TS, but apparently something makes a difference. 
Auto-SRC tests almost always work. Typical Auto-SRC rate was ~250-260Hz 
saturating L3 bandwidth. Typical full RC-TS system rates were 10-200 Hz. 
Some observations: 
 - Yesturday we were able to run for about 80 min with full Run Control 
  and TS sending SVX data until I stopped it by hand around midnight. 
  We also started a stopped small runs quite a few times. Today, seemignly 
  the same configuration did not work. (At least for EVB/L3 it was 
  exactly the same. About TS one is never sure.) 
 - It appears that for slower rates we have more chance to succeed 
  starting the run successfully. Slower means <100 Hz. It still died 
  in  3-5 min in our test with only 13 Hz. 
 - It appears that we have large probability to succeed starting the run 
  if we start run from run control and from EVB close in time (~1sec or less) 
  if it is 5-10sec or more between these moments, there will be no events 
  at all seen by EVB. (Not high statistics observation). 
 - Often we see that no events go through, then there is a burst of ~100 
  events, and then again zero events for some 10min like interval. 
  Why it happens  it is hard to say, because people are trying things  
  meanwhile - pushing various buttons on SVX and RC controls. 
 -  Steve Nahn watched lights on the 1st floor while we were trying to start. 
  In that case I started EVB/L3 first. He say that we are polling VRB 
  (i.e. "VME" light is on). Then Petar starts Run Control with TS - SVX only. 
  A light on scramnet flashes. "VME" light on VRB goes of forever. 
  EVB/L3 sees no events. SVX controls report that "VRB busy" and Petar 
  tries to get out of me why we are not polling his VRB anymore. At this time 
  he can manually read out data from VRB many times and sees that they are 
  present and of the right kind. 
 
All this is accompanied by Zephyr messages that are mostly unknown to me. 
There are several types that I observed more than once: 
 
-------------------------------------------------- 
First type: 
 
DAQ INFO message at 12:51:00 on Tue Nov  2 1999 from b0eb21.fnal.gov 
Process tSend_2 
SCPU_ERR_BUF_LOST_EVT - Unable to find event for level 3 (tag 1114) 
 
DAQ INFO message at 12:51:00 on Tue Nov  2 1999 from b0eb21.fnal.gov 
Process tSend_2 
SCPU_ERR Can't find event to send. Tag = 0x8b51 
 
DAQ INFO message at 12:51:00 on Tue Nov  2 1999 from b0eb21.fnal.gov 
Process tSend_2 
SCPU_ERR Can't send event. Tag = 0x8b51 
 
 
-------------------------------------------- 
Second type: 
 
DAQ INFO message at 12:37:45 on Tue Nov  2 1999 from b0eb21.fnal.gov 
Process tCtrl_0 
SCPU_ERR  writing zero tag to scramnet 
 
 
-------------------------------------------- 
Third type: 
 
DAQ INFO message at 10:53:49 on Tue Nov  2 1999 from b0eb10.fnal.gov 
Process tsmDisp 
SM_ERR - Just an error. 
Boss sent unknown command. 
 
 
-------------------------------------------- 
 
Sometimes the following error comes with any of the above types: 
 
DAQ INFO message at 12:36:24 on Tue Nov  2 1999 from b0eb10.fnal.gov 
Process tsmDisp 
SM Dispatcher: unexpected error (31, 307ff). (<- numbers are varied) 
--------------------------------------------- 
 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Mon Nov 8 20:02:09 1999 -->
<pre> 
    The results of today: 
 
 - We were able to read out 3 subsystems - cmu01, pcal and SVX. 
Level 3 was not running reformater nor executable, this will 
have to wait until tomorrow. 
 
 - This is the first successfull test after SVX hardware has 
been rearranged and in addition, the new code of event builder 
and level3 from Jeff and Steve Tether with some major changes was  
tested today. 
 
 - With Arnd, Steve Nahn, Jeff, ... we started the system for overnight 
run (trivial level3, no reformatter). Anyone should feel free to  
stop it in the morning or earlier if there is important work to  
be done. 
 
 - The work on power supplies on the 1st floor is officially finished. 
We should be able to bring up 15 all SCPUs. 
 
Problems: 
 
   - We could not run with SVX using VRB and SCPU in the same 
crate. With Auto-SRC trigger it was fine but with TS we saw  
VME bus errors. Therefore we moved active VRB into a different 
crate. After everything was sorted out ( took some amount of  
expert time) we were finally able to run successfully.  
We will probably need to try again VRB in the same with SRC crate 
and understand the problem. 
 
 - I still need to figure out how to run the full level3 with 
reformatter and executable for the latest version of it, but this  
should be easy with Jeff's help. 
 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Tue Nov 9 19:30:42 1999 -->
<pre> 
  This evening I have started the system with 4 crates of TDC  
and calorimeter and  one SVX VRB with the full chain of event 
 flow, including the reformatter, real executable and consumer 
 server which writes data to disk, all controlled by RC with TS. 
 I will leave it running as usual,  until tomorrow morning or 
 untill someone stops it. 
 
   The data written to disk are on b0dau31 in /logger/disk1/csl/.open 
directory. This file will be moved one directory up 
with appropriate date once the run is finished. 
I have looked at them using ~chlebana/bin/BNK_bank_dump, 
it prints out a lot of banks and does not crash. Perhaps 
people who know how to run a consumer could try it if you notice my 
mail why it is still running. 
 
 
  Other progress of today: 
 
  - Jeff has set up the full level3 for our tests  
 
  - we realized that level3 executable will have to be modified. 
  Meanwhile, Jeff did a kludge to our code so that we can run 
  for now. 
 
  - communicating with SVX we observed more of "VME bus error" 
  events. Steve Nahn has moved jumpers on SVX spus so that they 
  are never main controllers. Still problem remains. We see 
  these errors even when we try to read "scan busy" registers 
  and such from VRB while EVB is running. 
    Generally we can have quite conditions during dta taking, 
  but the system now is easy to break, For example, if someone 
  will try to monitor VRBs accessing registers once every X seconds 
  it might badly interfere with the event builder. We will have to 
  understand this better. 
 
  - on the negative side, it took us awhile again to start everything 
  and to sort out little problems. 
 
Ilya 
</pre>
<!-- Author: Ilya Kravchenko -->


<!-- Date: Wed Nov 10 15:30:42 1999 -->
<pre> Here are instructions from Jeff about how to set up ups on 
level 3 farm, 
 
------------------------------------------------------- 
 
nodes? 
 
(as superuser) 
1.  edit /etc/fstab, adding the line 
 
b0l3serv:/usr/products  /usr/products           nfs      
soft,rsize=8192,wsize=8192  0 0 
 
    (see b0l3019's /etc/fstab for example) 
 
2.  exec the following: 
        # cd /usr 
        # mkdir products 
        # mount /usr/products 
        # df 
    the last command just checks to make sure /usr/products has been mounted. 
 
3.  edit /fnal/ups/etc/upsdb_list, adding the line 
 
/usr/products/upsdb 
 
    (again, see b0l3019's /fnal/ups/etc/upsdb_list for example) 
 
4.  log into the node again, and test with "setup -d level3" and "ups list". 
 
</pre>
<!-- Author: Ilya Kravchenko -->