[12:38:23.009] INFO: *** Welcome to pxar ***
[12:38:23.009] INFO: *** Today: 2016/05/24
[12:38:23.160] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:38:23.160] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//dacParameters35_C15.dat
[12:38:23.194] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:38:23.194] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//defaultMaskFile.dat
[12:38:23.201] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C15.dat
[12:38:23.322] INFO: clk: 4
[12:38:23.322] INFO: ctr: 4
[12:38:23.322] INFO: sda: 19
[12:38:23.322] INFO: tin: 9
[12:38:23.322] INFO: level: 15
[12:38:23.322] INFO: triggerdelay: 0
[12:38:23.322] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:38:23.322] INFO: Log level: INFO
[12:38:23.340] QUIET: Connection to board DTB_WREKRL opened.
[12:38:23.343] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[12:38:23.346] INFO: RPC call hashes of host and DTB match: 398089610
[12:38:24.876] INFO: DUT info:
[12:38:24.876] INFO: The DUT currently contains the following objects:
[12:38:24.876] INFO: 2 TBM Cores tbm08c (2 ON)
[12:38:24.876] INFO: TBM Core alpha (0): 7 registers set
[12:38:24.876] INFO: TBM Core beta (1): 7 registers set
[12:38:24.876] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:38:24.876] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.876] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.876] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.876] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:24.877] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:25.281] INFO: enter 'restricted' command line mode
[12:38:25.281] INFO: enter test to run
[12:38:36.110] INFO: test: PixelAlive no parameter change
[12:38:36.110] INFO: running: pixelalive
[12:38:36.119] INFO: ----------------------------------------------------------------------
[12:38:36.120] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:38:36.120] INFO: ----------------------------------------------------------------------
[12:38:36.440] INFO: Expecting 41600 events.
[12:38:40.779] INFO: 41600 events read in total (3620ms).
[12:38:40.948] INFO: Test took 4826ms.
[12:38:40.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:41.223] INFO: PixTestAlive::aliveTest() done
[12:38:41.223] INFO: number of dead pixels (per ROC): 1 0 0 1 0 0 0 0 1 0 0 0 0 0 0 0
[12:38:41.262] INFO: enter test to run
[12:39:20.926] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:39:20.926] INFO: running: highrate
[12:39:20.926] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:39:21.121] INFO: ----------------------------------------------------------------------
[12:39:21.121] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:39:21.121] INFO: ----------------------------------------------------------------------
[12:39:21.121] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:39:21.121] INFO: edge/corner pixel THR is adjusted
[12:39:21.121] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:39:22.080] INFO: Collecting data for 5 seconds...
[12:39:27.096] INFO: Done with hot pixel readout
[12:39:38.410] INFO: PixTest:: pg_setup set to default.
[12:39:38.411] INFO: 1 hot pixels found in step 0
[12:39:39.402] INFO: Collecting data for 5 seconds...
[12:39:44.418] INFO: Done with hot pixel readout
[12:39:55.375] WARNING: Channel 1 ROC 2: Readback start marker after 14 readouts!
[12:39:55.376] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[12:39:55.376] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a130 80b1 43c9 43c9 510 2643 43c9 509 2240 43c9 6d0 2240 80d 264f 43c9 43c9 109 2a4d 43c9 43c9 e000 c000
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12a 8000 4388 4388 12 246c 4388 4388 4388 4388 4388 75a 2243 4388 5a 282f e000 c000
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12b 8040 4388 4388 760 2849 4388 4388 4388 4388 4388 4388 e000 c000
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12c 80b1 4388 4388 4388 81c 2840 4388 a 2040 114 2044 443 204d 4388 4388 4388 4388 e000 c000
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12d 80c0 43c8 68a 2a4c 10 25a6 43c8 43ca 43c8 549 2a4e 610 224f 43c8 43c8 43c8 e000 c000
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12e 8000 43c8 43c8 353 206d 43c8 8a 2449 205 224e 43c9 43ca 85c 224d 43c8 43c8 43c8 e000 c000
[12:39:55.376] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12f 8040 43ca 43ca 43ca 43c8 43c9 43ca 43ca 43ca e000 c000
[12:39:56.135] INFO: PixTest:: pg_setup set to default.
[12:39:56.135] INFO: 1 hot pixels found in step 1
[12:39:57.131] INFO: Collecting data for 5 seconds...
[12:40:02.147] INFO: Done with hot pixel readout
[12:40:07.995] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 has NoTokenPass but 8 ROCs were found
[12:40:07.995] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a07e 8000 43c8 43c8 18 224f 43ca 642 224c 43c8 c9 2645 43c8 15b 2229 6d1 204e 43ca 60c 224f 43ca 43ca e000 c000
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a078 80b1 4388 4388 4388 4388 4388 4388 e1 2649 4388 4388 e000 c000
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a079 80c0 4388 4388 4388 410 222f 4388 4388 55 286f 34c 2042 4388 6d1 2840 4388 49 2849 4388 e000 c000
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a07a 8000 4388 4388 4388 4388 4388 4388 4388 4388 e000 c000
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a07b 8040 4388 4d3 284c 4388 219 2245 4388 755 224c 4388 4388 111 2226 20b 2a4d 34b 2043 34b 224b 43c8 43c8 43c8 7fd 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a07c 80b1 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[12:40:07.995] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a07d 80c0 43c8 43c8 43c8 850 264f 43c8 43c8 43c8 84a 222a 43c8 341 2a2d 43c8 e000 c000
[12:40:08.731] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[12:40:08.731] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0db 8040 4388 4388 4388 4388 4388 4388 4a1 244d 4388 60a 2247 4388 21d 224d e000 c000
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d5 80c0 43c8 43c8 43c8 43c8 43c8 504 262f 43c8 43c8 43c8 e000 c000
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d6 8000 43c8 43c8 0 2647 43c8 43c8 43c8 11d 202d 43c8 84 242c 45b 2045 43c8 859 2048 43c8 e000 c000
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d7 8040 43c8 22 2840 43c8 43c8 43c8 10d 242c 43c8 43c8 43c8 43c8 e000 c000
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d8 80b1 43c8 60 2440 5b 2860 43c8 43c8 43c8 59 282e 4388 4388 408 4388 e000 c000
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d9 80c0 4388 4388 48c 244d 4388 4388 51b 2649 4388 108 282d 6d8 244d 4388 808 2845 4388 350 2428 4388 e000 c000
[12:40:08.731] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0da 8000 4388 4388 4388 4388 64c 242e 84d 2448 4388 4388 4388 28a 224c 4388 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[12:40:09.455] WARNING: Channel 1 ROC 0: Readback start marker after 6 readouts!
[12:40:09.455] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (4) != Token Chain Length (8)
[12:40:09.455] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a038 80b1 4388 4388 4388 401 2842 550 282f 4388 4388 14d 2a27 29c 2240 4388 40c 206a 4388 4388 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a032 8000 43c8 43c8 43c8 43c9 43c8 43c9 719 244c 43c8 43c9 449 2a47 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a033 8040 43c8 43c9 553 204d 43c8 43c9 43c8 91 2845 43c8 43c8 818 264d 43c8 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a034 80b1 43c8 43c8 43c8 43c8 48 222e 43c8 10 244f 43c8 43c8 848 2a4f 43c8 488 262d 559 2a4f e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a035 80c0 5388 1553 2517 c80 2d2b eb8 4388 4388 4388 4388 10b 284d e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a036 8000 4388 4388 4388 493 246c 4388 30c 202f 4388 849 2a61 4388 68c 2821 4388 4388 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a037 8040 4388 4388 4388 4388 52 2440 4388 121 2245 4388 44d 2641 4388 4388 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a138 80b1 4388 4388 4388 4388 4388 4388 4388 4388 65b 2840 e000 c000
[12:40:09.455] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a132 8000 43c8 43c8 43c9 543 264f 43c8 43c8 413 2644 43c8 43c9 43c9 e000 c000
[12:40:09.456] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a133 8040 43c8 43c9 43c8 10d 2440 811 2040 43c8 43c8 14 2046 43c9 43c8 43c9 e000 c000
[12:40:09.456] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a134 80b1 43c8 43c8 760 2447 43c8 4b 2047 43c8 43c8 9 264e 420 2664 458 2045 43c8 43c8 43c8 e000 c000
[12:40:09.456] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a135 80c0 538a 1806 2842 83f 29c1 41c 232d a24 4388 4388 1d 204c 4d9 2a6c 4388 4388 e000 c000
[12:40:09.456] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a136 8000 4388 2cd 244c 758 2068 4388 4388 4388 4388 4388 358 2647 4388 4388 e000 c000
[12:40:09.456] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a137 8040 4388 a0 204d 4388 4388 290 2865 321 2665 4388 203 244e 203 204b 4388 4388 4388 4388 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (0) != Token Chain Length (8)
[12:40:12.524] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (29) != TBM ID (30)
[12:40:12.524] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!
[12:40:12.524] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (29) != TBM ID (30)
[12:40:12.524] WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:40:12.524] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!
[12:40:12.524] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!
[12:40:12.524] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[12:40:12.524] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a021 80c0 43c8 68a 2a2a 43c8 55c 2645 43c9 43c8 43c9 43c8 410 2645 43c9 43c9 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a01b 8040 4388 818 2844 4388 4388 64a 286d 4388 4388 4388 559 2865 4388 6d2 224c 4388 14 2042 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a01c 80b1 4388 51b 202e 4388 4388 4388 4388 4388 4388 30b 284f 4388 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a03f c00b
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a01e 8000 43c8 118 2864 43c8 14 2665 43ca 43c8 43c8 43ca 43ca 43ca e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a01f 8040 43ca 43ca 43c8 19 204c 483 284f 43ca 84a 2444 43ca 43c8 43c8 43c8 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a020 80b1 43c8 218 2844 43c8 55a 2228 43c8 43c8 b 2a61 43c8 43c9 43c9 43c9 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a122 8000 43c8 84 2044 43c8 11 2449 119 2a4a 43c9 c 244d 43c8 43c8 2c3 2645 43c8 d9 244d 43c9 43c9 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a11b 8040 4388 29c 224c 2c9 2447 4388 213 2848 320 2465 4388 4388 4388 4388 4388 4388 51b 2a4f e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a11c 80b1 4388 4388 4c9 204d 4388 2dd 204c 609 2a47 4388 4388 4388 4388 4388 e000 c000
[12:40:12.524] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a11e 8000 43c8 43c8 43c8 448 2045 445 2864 43c9 98 2045 43ca 43c8 35b 244f 43c8 43c8 e000 c000
[12:40:12.525] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a11f 8040 43ca 43ca 109 2040 43ca 43c8 43c9 43ca 43ca 43ca e000 c000
[12:40:12.525] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a120 80b1 43c9 43c9 1a 2447 43c9 118 2841 43c9 43c9 2dd 2262 622 2a49 43c9 34a 2047 43c9 43c9 e000 c000
[12:40:12.525] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a121 80c0 43c8 43c8 43c8 43c9 43c8 43c9 2c8 262f 43c9 43c9 e000 c000
[12:40:14.228] INFO: PixTest:: pg_setup set to default.
[12:40:14.229] INFO: 0 hot pixels found in step 2
[12:40:14.265] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:40:14.268] INFO: PixTest::trimHotPixels() done
[12:40:14.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C0.dat
[12:40:14.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C1.dat
[12:40:14.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C2.dat
[12:40:14.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C3.dat
[12:40:14.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C4.dat
[12:40:14.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C5.dat
[12:40:14.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C6.dat
[12:40:14.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C7.dat
[12:40:14.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C8.dat
[12:40:14.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C9.dat
[12:40:14.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C10.dat
[12:40:14.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C11.dat
[12:40:14.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C12.dat
[12:40:14.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C13.dat
[12:40:14.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C14.dat
[12:40:14.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C15.dat
[12:40:14.354] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//defaultMaskFile.dat
[12:40:14.364] INFO: enter test to run
[12:41:16.453] INFO: test: timing no parameter change
[12:41:16.453] INFO: running: timing
[12:41:16.474] INFO: ######################################################################
[12:41:16.474] INFO: PixTestTiming::doTest()
[12:41:16.474] INFO: ######################################################################
[12:41:16.475] INFO: ----------------------------------------------------------------------
[12:41:16.475] INFO: PixTestTiming::TBMPhaseScan()
[12:41:16.475] INFO: ----------------------------------------------------------------------
[12:46:09.523] INFO: TBM Phase Settings: 236
[12:46:09.523] INFO: 400MHz Phase: 3
[12:46:09.523] INFO: 160MHz Phase: 7
[12:46:09.524] INFO: Functional Phase Area: 3
[12:46:09.527] INFO: Test took 293053 ms.
[12:46:09.527] INFO: PixTestTiming::TBMPhaseScan() done.
[12:46:09.527] INFO: ----------------------------------------------------------------------
[12:46:09.527] INFO: PixTestTiming::ROCDelayScan()
[12:46:09.527] INFO: ----------------------------------------------------------------------
[12:48:41.732] INFO: ROC Delay Settings: 228
[12:48:41.732] INFO: ROC Header-Trailer/Token Delay: 11
[12:48:41.732] INFO: ROC Port 0 Delay: 4
[12:48:41.732] INFO: ROC Port 1 Delay: 4
[12:48:41.732] INFO: Functional ROC Area: 4
[12:48:41.735] INFO: Test took 152208 ms.
[12:48:41.736] INFO: PixTestTiming::ROCDelayScan() done.
[12:48:41.736] INFO: ----------------------------------------------------------------------
[12:48:41.736] INFO: PixTestTiming::TimingTest()
[12:48:41.736] INFO: ----------------------------------------------------------------------
[12:48:57.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:12.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:27.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:42.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:57.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:12.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:27.640] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:42.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:57.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:12.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:12.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:12.930] INFO: ----------------------------------------------------------------------
[12:51:12.930] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:51:12.930] INFO: ----------------------------------------------------------------------
[12:51:12.930] INFO: ----------------------------------------------------------------------
[12:51:12.930] INFO: Read back bit status: 1
[12:51:12.930] INFO: ----------------------------------------------------------------------
[12:51:12.930] INFO: ----------------------------------------------------------------------
[12:51:12.930] INFO: Timings are good!
[12:51:12.930] INFO: ----------------------------------------------------------------------
[12:51:12.930] INFO: Test took 151194 ms.
[12:51:12.930] INFO: PixTestTiming::TimingTest() done.
[12:51:12.931] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:51:12.931] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:51:12.931] INFO: PixTestTiming::doTest took 596460 ms.
[12:51:12.931] INFO: PixTestTiming::doTest() done
[12:51:12.931] INFO: Write out TBMPhaseScan_0_V0
[12:51:12.931] INFO: Write out TBMPhaseScan_1_V0
[12:51:12.931] INFO: Write out CombinedTBMPhaseScan_V0
[12:51:12.933] INFO: Write out ROCDelayScan3_V0
[12:51:12.934] INFO: enter test to run
[12:52:02.344] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:52:02.344] INFO: running: highrate
[12:52:02.349] INFO: ----------------------------------------------------------------------
[12:52:02.349] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:52:02.349] INFO: ----------------------------------------------------------------------
[12:52:02.349] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:52:02.349] INFO: edge/corner pixel THR is adjusted
[12:52:02.349] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:52:03.307] INFO: Collecting data for 5 seconds...
[12:52:08.323] INFO: Done with hot pixel readout
[12:52:19.985] INFO: PixTest:: pg_setup set to default.
[12:52:19.986] INFO: 0 hot pixels found in step 0
[12:52:20.026] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:52:20.030] INFO: PixTest::trimHotPixels() done
[12:52:20.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C0.dat
[12:52:20.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C1.dat
[12:52:20.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C2.dat
[12:52:20.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C3.dat
[12:52:20.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C4.dat
[12:52:20.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C5.dat
[12:52:20.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C6.dat
[12:52:20.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C7.dat
[12:52:20.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C8.dat
[12:52:20.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C9.dat
[12:52:20.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C10.dat
[12:52:20.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C11.dat
[12:52:20.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C12.dat
[12:52:20.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C13.dat
[12:52:20.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C14.dat
[12:52:20.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C15.dat
[12:52:20.114] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//defaultMaskFile.dat
[12:52:20.124] INFO: enter test to run
[12:53:20.672] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:53:20.672] INFO: running: highrate
[12:53:20.676] INFO: ----------------------------------------------------------------------
[12:53:20.676] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:53:20.676] INFO: ----------------------------------------------------------------------
[12:53:20.676] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:53:20.676] INFO: edge/corner pixel THR is adjusted
[12:53:20.676] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:53:21.633] INFO: Collecting data for 1 seconds...
[12:53:22.637] INFO: Done with hot pixel readout
[12:53:26.693] INFO: PixTest:: pg_setup set to default.
[12:53:26.694] INFO: 0 hot pixels found in step 0
[12:53:26.699] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:53:26.790] INFO: PixTest::trimHotPixels() done
[12:53:26.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C0.dat
[12:53:26.798] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C1.dat
[12:53:26.803] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C2.dat
[12:53:26.809] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C3.dat
[12:53:26.814] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C4.dat
[12:53:26.819] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C5.dat
[12:53:26.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C6.dat
[12:53:26.829] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C7.dat
[12:53:26.835] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C8.dat
[12:53:26.840] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C9.dat
[12:53:26.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C10.dat
[12:53:26.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C11.dat
[12:53:26.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C12.dat
[12:53:26.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C13.dat
[12:53:26.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C14.dat
[12:53:26.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//trimParameters35_C15.dat
[12:53:26.876] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-18_FPIXTest-17C-FNAL-160520-1215_2016-05-20_12h15m_1463764545/000_FPIXTest_p17//defaultMaskFile.dat
[12:53:26.886] INFO: enter test to run
[12:54:15.775] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:54:15.775] INFO: running: xray
[12:54:15.776] INFO: ----------------------------------------------------------------------
[12:54:15.776] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:54:15.776] INFO: ----------------------------------------------------------------------
[12:54:16.741] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:54:28.269] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:54:57.263] INFO: Resuming triggers.
[12:55:08.793] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:55:37.981] INFO: Resuming triggers.
[12:55:49.510] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:56:17.946] INFO: Resuming triggers.
[12:56:29.475] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:56:59.400] INFO: Resuming triggers.
[12:57:10.928] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:57:40.461] INFO: Resuming triggers.
[12:57:51.990] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:58:21.359] INFO: Resuming triggers.
[12:58:32.884] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:59:02.361] INFO: Resuming triggers.
[12:59:13.890] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:59:43.367] INFO: Resuming triggers.
[12:59:51.467] INFO: data taking finished, elapsed time: 100 seconds.
[13:00:12.326] INFO: PixTest:: pg_setup set to default.
[13:00:12.329] INFO: PixTestXray::doPhRun() done
[13:00:12.465] INFO: enter test to run
[13:01:00.892] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:01:00.892] INFO: running: xray
[13:01:00.893] INFO: ----------------------------------------------------------------------
[13:01:00.893] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:01:00.893] INFO: ----------------------------------------------------------------------
[13:01:01.858] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:01:08.512] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:01:38.728] INFO: Resuming triggers.
[13:01:45.381] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:02:15.541] INFO: Resuming triggers.
[13:02:22.194] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:02:52.377] INFO: Resuming triggers.
[13:02:59.033] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:03:29.228] INFO: Resuming triggers.
[13:03:35.881] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:04:06.146] INFO: Resuming triggers.
[13:04:12.801] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:04:42.990] INFO: Resuming triggers.
[13:04:49.649] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:05:19.910] INFO: Resuming triggers.
[13:05:26.565] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:05:57.350] INFO: Resuming triggers.
[13:06:04.006] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:06:33.981] INFO: Resuming triggers.
[13:06:40.639] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:07:10.891] INFO: Resuming triggers.
[13:07:17.548] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[13:07:48.059] INFO: Resuming triggers.
[13:07:54.714] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:08:25.774] INFO: Resuming triggers.
[13:08:32.429] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:09:02.639] INFO: Resuming triggers.
[13:09:09.291] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:09:39.439] INFO: Resuming triggers.
[13:09:46.093] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:10:15.950] INFO: Resuming triggers.
[13:10:16.449] INFO: data taking finished, elapsed time: 100 seconds.
[13:10:19.066] INFO: PixTest:: pg_setup set to default.
[13:10:19.069] INFO: PixTestXray::doPhRun() done
[13:10:19.243] INFO: enter test to run
[13:11:38.032] INFO: test: HighRate no parameter change
[13:11:38.032] INFO: running: highrate
[13:11:38.048] INFO: ----------------------------------------------------------------------
[13:11:38.048] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:11:38.048] INFO: ----------------------------------------------------------------------
[13:11:38.190] INFO: Expecting 768 events.
[13:11:39.324] INFO: 768 events read in total (418ms).
[13:11:39.324] INFO: Test took 1268ms.
[13:11:40.128] INFO: Expecting 41600 events.
[13:11:43.194] INFO: 41600 events read in total (2539ms).
[13:11:43.195] INFO: Test took 3863ms.
[13:11:43.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:43.955] INFO: Expecting 41600 events.
[13:11:47.156] INFO: 41600 events read in total (2674ms).
[13:11:47.157] INFO: Test took 3913ms.
[13:11:47.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:47.914] INFO: Expecting 41600 events.
[13:11:51.141] INFO: 41600 events read in total (2700ms).
[13:11:51.142] INFO: Test took 3933ms.
[13:11:51.175] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:51.900] INFO: Expecting 41600 events.
[13:11:55.136] INFO: 41600 events read in total (2709ms).
[13:11:55.137] INFO: Test took 3945ms.
[13:11:55.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:55.893] INFO: Expecting 41600 events.
[13:11:59.157] INFO: 41600 events read in total (2737ms).
[13:11:59.158] INFO: Test took 3969ms.
[13:11:59.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:59.914] INFO: Expecting 41600 events.
[13:12:03.152] INFO: 41600 events read in total (2711ms).
[13:12:03.153] INFO: Test took 3943ms.
[13:12:03.187] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:03.909] INFO: Expecting 41600 events.
[13:12:07.142] INFO: 41600 events read in total (2706ms).
[13:12:07.143] INFO: Test took 3938ms.
[13:12:07.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:07.904] INFO: Expecting 41600 events.
[13:12:11.147] INFO: 41600 events read in total (2716ms).
[13:12:11.147] INFO: Test took 3952ms.
[13:12:11.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:11.907] INFO: Expecting 41600 events.
[13:12:15.166] INFO: 41600 events read in total (2732ms).
[13:12:15.167] INFO: Test took 3969ms.
[13:12:15.200] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:15.925] INFO: Expecting 41600 events.
[13:12:19.165] INFO: 41600 events read in total (2713ms).
[13:12:19.166] INFO: Test took 3949ms.
[13:12:19.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:19.926] INFO: Expecting 41600 events.
[13:12:23.169] INFO: 41600 events read in total (2717ms).
[13:12:23.170] INFO: Test took 3952ms.
[13:12:23.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:23.927] INFO: Expecting 41600 events.
[13:12:27.169] INFO: 41600 events read in total (2715ms).
[13:12:27.170] INFO: Test took 3948ms.
[13:12:27.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:27.930] INFO: Expecting 41600 events.
[13:12:31.179] INFO: 41600 events read in total (2722ms).
[13:12:31.180] INFO: Test took 3959ms.
[13:12:31.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:31.940] INFO: Expecting 41600 events.
[13:12:35.181] INFO: 41600 events read in total (2714ms).
[13:12:35.182] INFO: Test took 3951ms.
[13:12:35.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:35.938] INFO: Expecting 41600 events.
[13:12:39.181] INFO: 41600 events read in total (2716ms).
[13:12:39.182] INFO: Test took 3947ms.
[13:12:39.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:39.942] INFO: Expecting 41600 events.
[13:12:43.187] INFO: 41600 events read in total (2718ms).
[13:12:43.188] INFO: Test took 3956ms.
[13:12:43.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:43.948] INFO: Expecting 41600 events.
[13:12:47.180] INFO: 41600 events read in total (2705ms).
[13:12:47.181] INFO: Test took 3943ms.
[13:12:47.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:47.938] INFO: Expecting 41600 events.
[13:12:51.180] INFO: 41600 events read in total (2715ms).
[13:12:51.181] INFO: Test took 3949ms.
[13:12:51.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:51.941] INFO: Expecting 41600 events.
[13:12:55.178] INFO: 41600 events read in total (2710ms).
[13:12:55.179] INFO: Test took 3946ms.
[13:12:55.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:55.941] INFO: Expecting 41600 events.
[13:12:59.088] INFO: 41600 events read in total (2621ms).
[13:12:59.089] INFO: Test took 3860ms.
[13:12:59.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:59.485] INFO: enter test to run
[13:13:34.479] INFO: test: HighRate no parameter change
[13:13:34.479] INFO: running: highrate
[13:13:34.480] INFO: ----------------------------------------------------------------------
[13:13:34.480] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:13:34.480] INFO: ----------------------------------------------------------------------
[13:13:35.095] INFO: Expecting 208000 events.
[13:13:46.951] INFO: 208000 events read in total (11330ms).
[13:13:46.954] INFO: Test took 12465ms.
[13:13:47.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:47.348] INFO: number of dead pixels (per ROC): 1 0 0 1 0 0 0 0 3 0 0 0 0 0 0 0
[13:13:47.348] INFO: number of red-efficiency pixels: 59 42 70 110 103 127 156 119 104 122 135 85 104 58 22 25
[13:13:47.348] INFO: number of X-ray hits detected: 57615 41579 65870 101210 110188 106194 114868 83936 77931 97781 96780 81428 86353 51321 21372 25600
[13:13:47.348] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:13:47.348] INFO: number of Vcal hits detected: 207890 207958 207930 207838 207892 207869 207840 207878 207748 207876 207862 207913 207896 207940 207977 207975
[13:13:47.348] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:13:47.348] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:13:47.348] INFO: X-ray hit rate [MHz/cm2]: 16.9 12.2 19.3 29.7 32.3 31.1 33.7 24.6 22.8 28.7 28.4 23.9 25.3 15.0 6.3 7.5
[13:13:47.348] INFO: PixTestHighRate::doXPixelAlive() done
[13:13:47.396] INFO: PixTest:: pg_setup set to default.
[13:13:47.407] INFO: enter test to run
[13:14:18.534] INFO: test: HighRate no parameter change
[13:14:18.534] INFO: running: highrate
[13:14:18.536] INFO: ----------------------------------------------------------------------
[13:14:18.536] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:14:18.536] INFO: ----------------------------------------------------------------------
[13:14:19.153] INFO: Expecting 208000 events.
[13:14:32.661] INFO: 208000 events read in total (12981ms).
[13:14:32.666] INFO: Test took 14121ms.
[13:14:32.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:33.252] INFO: number of dead pixels (per ROC): 1 0 0 1 0 0 0 0 3 0 0 0 0 0 0 0
[13:14:33.253] INFO: number of red-efficiency pixels: 183 131 206 355 374 456 603 337 299 329 381 265 325 195 53 65
[13:14:33.253] INFO: number of X-ray hits detected: 121040 86554 138428 211251 229537 220959 239203 175667 162539 203905 202830 170701 180902 107501 44761 53054
[13:14:33.253] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:14:33.253] INFO: number of Vcal hits detected: 207755 207866 207783 207570 207597 207495 207320 207622 207540 207652 207590 207727 207650 207789 207947 207935
[13:14:33.253] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:14:33.253] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[13:14:33.253] INFO: X-ray hit rate [MHz/cm2]: 35.5 25.4 40.6 61.9 67.3 64.8 70.1 51.5 47.6 59.8 59.5 50.0 53.0 31.5 13.1 15.6
[13:14:33.253] INFO: PixTestHighRate::doXPixelAlive() done
[13:14:33.300] INFO: PixTest:: pg_setup set to default.
[13:14:33.316] INFO: enter test to run
[13:14:57.734] INFO: test: HighRate no parameter change
[13:14:57.734] INFO: running: highrate
[13:14:57.735] INFO: ----------------------------------------------------------------------
[13:14:57.735] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:14:57.735] INFO: ----------------------------------------------------------------------
[13:14:58.351] INFO: Expecting 208000 events.
[13:15:13.941] INFO: 208000 events read in total (15063ms).
[13:15:13.949] INFO: Test took 16205ms.
[13:15:14.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:14.737] INFO: number of dead pixels (per ROC): 1 0 0 1 0 0 0 0 3 0 0 0 0 0 0 0
[13:15:14.737] INFO: number of red-efficiency pixels: 425 236 503 804 931 1126 1396 872 682 736 987 517 728 428 107 108
[13:15:14.737] INFO: number of X-ray hits detected: 187453 134257 213383 326570 353377 340911 368600 270273 252388 315608 312798 264219 279628 167421 69758 81908
[13:15:14.737] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:15:14.737] INFO: number of Vcal hits detected: 207456 207741 207365 207006 206882 206530 206142 206855 207079 207155 206832 207425 207154 207479 207886 207888
[13:15:14.737] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.5 99.4 99.2 99.5 99.7 99.6 99.5 99.8 99.6 99.8 99.9 99.9
[13:15:14.737] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.5 99.3 99.1 99.4 99.6 99.6 99.4 99.7 99.6 99.7 99.9 99.9
[13:15:14.737] INFO: X-ray hit rate [MHz/cm2]: 54.9 39.4 62.5 95.7 103.6 99.9 108.0 79.2 74.0 92.5 91.7 77.4 82.0 49.1 20.4 24.0
[13:15:14.737] INFO: PixTestHighRate::doXPixelAlive() done
[13:15:14.786] INFO: PixTest:: pg_setup set to default.
[13:15:14.802] INFO: enter test to run
[13:15:45.030] INFO: test: exit no parameter change
[13:15:45.412] QUIET: Connection to board 33 closed.
[13:15:45.414] INFO: pXar: this is the end, my friend