[13:05:12.553] INFO: *** Welcome to pxar ***
[13:05:12.553] INFO: *** Today: 2016/05/17
[13:05:12.646] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:05:12.646] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//dacParameters35_C15.dat
[13:05:12.667] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:05:12.668] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//defaultMaskFile.dat
[13:05:12.668] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C15.dat
[13:05:12.749] INFO: clk: 4
[13:05:12.749] INFO: ctr: 4
[13:05:12.749] INFO: sda: 19
[13:05:12.749] INFO: tin: 9
[13:05:12.749] INFO: level: 15
[13:05:12.749] INFO: triggerdelay: 0
[13:05:12.749] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:05:12.749] INFO: Log level: INFO
[13:05:12.767] QUIET: Connection to board DTB_WREKRL opened.
[13:05:12.770] 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:
------------------------------------------------------
[13:05:12.773] INFO: RPC call hashes of host and DTB match: 398089610
[13:05:14.304] INFO: DUT info:
[13:05:14.304] INFO: The DUT currently contains the following objects:
[13:05:14.304] INFO: 2 TBM Cores tbm08c (2 ON)
[13:05:14.304] INFO: TBM Core alpha (0): 7 registers set
[13:05:14.304] INFO: TBM Core beta (1): 7 registers set
[13:05:14.304] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:05:14.304] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.304] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.305] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.305] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.305] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.305] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.305] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:05:14.708] INFO: enter 'restricted' command line mode
[13:05:14.708] INFO: enter test to run
[13:05:29.415] INFO: test: PixelAlive no parameter change
[13:05:29.415] INFO: running: pixelalive
[13:05:29.425] INFO: ----------------------------------------------------------------------
[13:05:29.425] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:05:29.425] INFO: ----------------------------------------------------------------------
[13:05:29.745] INFO: Expecting 41600 events.
[13:05:34.069] INFO: 41600 events read in total (3605ms).
[13:05:34.237] INFO: Test took 4810ms.
[13:05:34.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:34.560] INFO: PixTestAlive::aliveTest() done
[13:05:34.560] INFO: number of dead pixels (per ROC): 0 0 0 0 0 11 3 2 0 0 0 0 0 0 0 0
[13:05:34.594] INFO: enter test to run
[13:06:14.879] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:06:14.879] INFO: running: highrate
[13:06:14.879] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:06:15.110] INFO: ----------------------------------------------------------------------
[13:06:15.110] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:06:15.110] INFO: ----------------------------------------------------------------------
[13:06:15.110] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:06:15.110] INFO: edge/corner pixel THR is adjusted
[13:06:15.110] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:06:16.071] INFO: Collecting data for 5 seconds...
[13:06:21.088] INFO: Done with hot pixel readout
[13:06:32.752] INFO: PixTest:: pg_setup set to default.
[13:06:32.753] INFO: 17 hot pixels found in step 0
[13:06:33.743] INFO: Collecting data for 5 seconds...
[13:06:38.760] INFO: Done with hot pixel readout
[13:06:50.389] INFO: PixTest:: pg_setup set to default.
[13:06:50.390] INFO: 16 hot pixels found in step 1
[13:06:51.381] INFO: Collecting data for 5 seconds...
[13:06:56.399] INFO: Done with hot pixel readout
[13:07:08.067] INFO: PixTest:: pg_setup set to default.
[13:07:08.068] INFO: 16 hot pixels found in step 2
[13:07:09.059] INFO: Collecting data for 5 seconds...
[13:07:14.076] INFO: Done with hot pixel readout
[13:07:21.821] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 has NoTokenPass but 7 ROCs were found
[13:07:21.821] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a14b 8040 43c8 43c8 43c9 48d 262e 43c8 43c8 11c 244a 6c8 2040 759 224f 43c8 43c8 43c8 e000 c000
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a145 80c0 4388 4388 2c5 224f 301 2642 4388 4388 4388 4388 4388 4388 e000 c000
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a146 8000 4388 80c 262a 4388 4388 4388 4388 319 286a 4388 4388 4388 e000 c000
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a147 8040 4388 4388 68a 2828 4388 8a 2a65 4388 4388 4388 4388 4388 e000 c000
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a148 80b1 4388 4388 5b 244a 209 266a 438a 4388 d9 264a 4388 85b 266f 43c8 40d 2640 43c8 7f2 207c 0 21ff 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 fff 2fff fff
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a149 80c0 43c8 43c8 44b 2a4f 85a 2446 43c9 43c8 750 2423 43c8 43c8 43c8 43c8 e000 c000
[13:07:21.821] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a14a 8000 43c8 2a1 2a68 43c8 43c8 43c8 d8 244c 43c8 615 2462 43c8 43c8 43c8 e000 c000
[13:07:25.703] INFO: PixTest:: pg_setup set to default.
[13:07:25.704] INFO: 15 hot pixels found in step 3
[13:07:26.694] INFO: Collecting data for 5 seconds...
[13:07:31.711] INFO: Done with hot pixel readout
[13:07:33.396] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a001 80c0 43c8 43c8 43c8 43c9 43c9 43c9 43c9 408 2040 4c4 282b 43c8 459 2062 e000 c000
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0fb 8040 4388 4388 313 2a4a 721 2248 4388 4388 4388 d5 284a 6c2 2a4a 803 224f 4388 4388 611 224a 438a 4db 2848 540 264e e000 c000
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0fc 80b1 4388 4388 438a 618 2680 4388 85c 2662 4388 4388 4388 4388 14 2a40 341 2042 e000 c000
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0fd 80c0 4388 859 202c 858 282e 4388 48 242f 4388 4388 85 2864 4cd 2864 4388 4388 713 204f 4388 4389 e000 c000
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0fe 8000 4388 650 2646 4388 4388 438a c3 224b 4388 4388 544 2245 43c8 1214 284e 6d4 23bf 43c9 11d 2045 4db 284a e000 c000
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ff 8040 43ca d4 204f 43ca 518 202c 43c9 43c8 43ca 43ca da 2248 4c2 2243 43ca 43c9 e000 c000
[13:07:33.397] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a000 80b1 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:07:37.052] WARNING: Channel 1 ROC 1: Readback start marker after 4 readouts!
[13:07:37.052] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[13:07:37.052] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a046 8000 43c8 43c8 43c8 43c8 4a1 204f 43c8 493 2048 43c8 358 2a46 43c8 9b 2668 43c8 494 2a26 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a040 80b1 4388 855 244c 4388 4388 660 2643 4388 6cd 224f 4388 4388 4388 15b 2a6a 4388 40a 2a46 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a041 80c0 4388 4388 13 224a 4388 49c 2268 754 2849 4389 4389 4389 4389 4388 101 266f e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a042 8000 4388 4388 4388 9c 246d 4389 4388 4d 264c 4388 4389 4388 2d4 202e e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== b043 8040 43c8 c00a
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a044 80b1 43c8 43c8 43c8 43c8 4dd 2847 43c8 848 224f 43c8 688 2041 43c8 43c8 31b 2a4e 354 264f e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a045 80c0 43c8 555 2640 43c8 720 2849 43c8 43c8 d4 222e 43c8 61d 224a 43c8 43c8 43c8 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a146 8000 43c8 858 2640 43c8 14c 222b 14c 264c 254 2448 43c8 43c8 512 2a41 43c8 561 2044 43c8 43c8 43c8 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a140 80b1 4389 4389 8d 2428 605 2866 4388 4389 4389 289 2a4e 4389 4389 4389 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a141 80c0 4388 4388 4388 4388 4389 4388 4389 4389 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a142 8000 4388 409 284a 4388 8b 2a2c 4388 4389 4388 4389 40d 2846 4389 4389 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== b143 8040 43c8 43ca 10 2297 43c9 43c8 43c8 43c8 43c9 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a144 80b1 43c8 43c8 43c8 43c8 43c8 204 282a 221 2265 43c8 43c8 43c8 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a145 80c0 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:07:37.053] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 4: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!
[13:07:37.053] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!
[13:07:37.053] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a052 8000 43c8 650 2844 69c 242a 43c8 43c8 43c9 4c1 2640 43c8 814 264a 43c8 43c9 752 2667 43c8 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a04c 80b1 43c8 74b 2a4e 43c8 43ca 43c8 43c8 43c8 8c 2424 43c8 43c8 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a04d 80c0 43c8 43c8 43c8 43c8 43c8 d5 2a4f 60a 2a68 43c8 43c8 43c9 e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a04e 8000 43c8 43c8 43c8 43ca 43c8 719 2a4b 43c8 43c8 43c9 144 220f e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a04f 8040 43ca 43ca 43c9 43c8 21d 2862 43ca 43ca 1b 244f 44b 284e 43ca 304 282c 43c9 153 204b e000 c000
[13:07:37.053] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a050 80b1 43c8 43c8 43c8 548 2a2c 43c8 43c8 43c8 20 2048 108 284e 43c8 43c8 e000 c000
[13:07:37.054] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a051 80c0 43c8 61c 2444 43c8 43c8 43c9 34b 2a4b 43c9 43c9 550 224e 43c9 35b 224f 43c8 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[13:07:39.408] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[13:07:39.408] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d1 80c0 4388 4388 4388 853 284f 4389 4389 4389 4389 14 2648 54 2440 4388 15c 2a29 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cb 8040 43c8 43c8 43c8 510 2240 43c8 43c8 43c8 43c8 40c 2042 40b 2868 43ca e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cc 80b1 43c8 43c8 43ca 43c8 83 2082 43c8 852 2246 43c8 c 222e 55 286a 48 244c 48 202d 43c8 43c8 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cd 80c0 43c8 43c8 43c8 43c8 9b 2262 43c8 dd 204f 43c8 43c8 43c9 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ce 8000 43c8 20 202a 43c8 43c8 43ca 4d8 2062 548 2642 8f8 4388 4ca 2243 4388 4389 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cf 8040 438a 438a 4389 4388 45d 2443 438a 438a 345 2a45 438a 4389 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d0 80b1 4388 4388 4388 4388 851 2462 4388 4388 4388 4388 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d1 80c0 4388 4388 4388 4388 5 2444 4389 14b 2644 511 2a4a 4388 4389 720 2062 4389 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cb 8040 43c8 43c8 860 246f 43c9 818 2843 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:07:39.408] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cc 80b1 43c8 500 2840 43c8 43c8 43c8 61a 2a46 75d 2046 854 204a 43c8 6c9 2040 6cd 2a4c 43c8 43c8 43c8 e000 c000
[13:07:39.409] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cd 80c0 43c8 43c8 20a 2248 34a 2a40 43c8 43c8 45a 202c 43c8 43c8 43c8 43c8 e000 c000
[13:07:39.409] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ce 8000 43c8 43c8 701 244b 43c8 43c8 493 204f 4388 438a 7c 4388 e000 c000
[13:07:39.409] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cf 8040 438a 438a 550 2a27 4388 60b 2246 438a 50c 2642 438a 4389 438a 438a e000 c000
[13:07:39.409] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d0 80b1 4389 208 202c 4389 4388 d9 224e 4389 4389 4389 4389 4389 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (43) != TBM ID (42)
[13:07:40.101] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (43) != TBM ID (42)
[13:07:40.101] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[13:07:40.101] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (43) != TBM ID (44)
[13:07:40.101] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (43) != TBM ID (44)
[13:07:40.101] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a02f 8040 438a 410 2824 438a d1 206c 4389 4388 4cc 2a2f 438a 52 2a6f 438a 30c 282a 438a 4389 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a029 80c0 43c8 12 2026 43c8 1a 2068 43c8 43c8 43c8 43c8 43c8 345 2262 43c8 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a02a 8000 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 498 202b e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a02a 80a5 4388 4388 4388 4388 59 2645 2d9 2246 4c8 2041 4388 2db 244a 4388 694 2028 4388 438a e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a02c 80b1 4388 560 222e 4388 438a 4388 4388 4388 250 2a4a 4388 95 264a 4388 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a02d 80c0 4388 4388 4388 44b 2440 4388 4388 4388 4388 4389 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a02e 8000 4388 811 244e 4388 4388 438a 2d0 2026 6c9 284b 4388 4388 4388 4389 21 224e e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12f 8040 438a 438a 4388 309 2446 438a 438a 4389 438a 438a e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a129 80c0 43c8 604 282e 43c8 43c9 43c8 43c8 43c8 43c8 259 2a4f 43c8 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12a 8000 43c8 4dc 2a46 43c8 43c8 43c8 43c8 4d9 246e 43c8 43c8 43c8 e000 c000
[13:07:40.101] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12a 80a8 15c 4388 4389 6cb 2865 4388 4388 55b 2468 4388 4388 4388 e000 c000
[13:07:40.102] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12c 80b1 4388 6c2 264a 718 284e 4388 421 2842 4388 10 2646 4388 4388 4388 4388 4388 e000 c000
[13:07:40.102] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12d 80c0 4388 4388 10b 2666 2c1 224f 4388 4388 4388 4388 4388 4388 e000 c000
[13:07:40.102] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a12e 8000 4388 4388 814 2240 4388 4388 361 284f 4388 4c4 2462 438a 4388 4388 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 has NoTokenPass but 1 ROCs were found
[13:07:42.403] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (5) != Token Chain Length (8)
[13:07:42.403] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (183) != TBM ID (63)
[13:07:42.403] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (3) != Token Chain Length (8)
[13:07:42.403] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (64) != TBM ID (183)
[13:07:42.403] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b9 80c0 43c8 43c8 43c9 693 248a 820 206a 43c8 43c8 43c8 43c8 43c8 420 244d e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b3 8040 4388 400 264a 4389 6dd 2644 4388 760 2028 4389 4388 4388 4388 4389 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b4 80b1 4388 4388 554 262b 4388 cd 2044 4388 113 2842 48a 204f 4ca 2842 4388 4388 4388 4388 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b5 80c0 4388 4388 84a 224e 4388 4388 4388 4388 420 284e 4388 4388 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b6 8000 4388 4388 4388 43c8 43c8 89 2440 7e0 43c8 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b7 8040 43c8 43c8 60a 2a2a 61d 2646 43c8 43c8 253 204a 43c8 691 2448 683 2665 43c8 43c8 43c8 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b8 80b1 43c8 43c8 55d 2a48 43ca 43c8 560 224f 43c8 43c8 43c8 43c8 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ba 8000 43c8 43c8 43c8 43c8 43c8 43c8 8b 2042 43c8 43c8 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b5 80c0 4388 4388 491 282e 4388 4388 4388 503 2a4f 4388 65b 224c 4388 4388 49b 2442 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a0b6 8000 4388 762 264e 862 264e 43c8 114
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a03f 80c1 6aa 43c8 43c8 118 2a42 43c8 618 282b 60d 2267 81b 2068 43c8 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b7 8040 43c8 752 2468 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:07:42.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b8 80b1 43c8 43c8 43c8 43c8 8d 2082 8d 2666 43c8 43c8 43c8 9c 244a 43c8 e000 c000
[13:07:42.404] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b9 80c0 43c8 111 262e 43c8 43c8 43c8 43c8 43c8 651 204f 859 2a45 43c8 43c8 e000 c000
[13:07:43.535] INFO: PixTest:: pg_setup set to default.
[13:07:43.536] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:07:43.536] INFO: 16 hot pixels found in step 4
[13:07:44.528] INFO: Collecting data for 5 seconds...
[13:07:49.544] INFO: Done with hot pixel readout
[13:07:53.504] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (1) != TBM ID (65)
[13:07:53.504] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a143 8040 43c8 43c9 41b 244f 43c8 43c9 43c8 43c8 43c8 43c9 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a13d 80c0 4388 462 224f 4388 4388 4388 709 2a48 4388 4388 4388 4388 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a13e 8000 4388 4388 4388 4388 4388 438a 418 2649 4388 4388 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a13f 8040 438a 438a 19 204f 4388 438a 438a 4389 438a 438a e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a140 80b1 4389 80d 2a46 4389 4388 4389 4389 11b 2862 4389 a1 224e 43c9 53c9 e000 c03e
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a141 80c0 43c8 43c8 43c8 43c8 4dd 224c 43c9 43c8 43c9 43c9 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a142 8000 43c8 1a 2068 43c8 43c8 43c9 444 2829 482 284c 43c8 43c9 43c9 43c9 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a044 80b1 43c8 43c8 43c8 652 202e 43c8 4cb 204a 43c8 14 2443 4d 2668 43c8 320 2a40 43c8 43c8 85 2a4e 55b 2865 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a03f 8040 438a 438a 4389 4388 509 2a42 438a 438a 438a 4389 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a040 80b1 4388 4388 4388 4388 4388 853 2a42 4388 13 2842 4388 e1 2848 53c8 1450 2844 30f 2030
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a000 8001 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 fff 2fff fff 2fff
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a041 80c0 43c8 43c8 18 242f 43c8 43c9 14b 2242 43c9 853 224a 43c9 43c9 2cc 2660 43c8 e000 c000
[13:07:53.504] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a042 8000 43c8 43c8 43c8 43c9 742 2263 43c8 44c 204a 612 244a 43c8 28b 2248 84b 2869 43c9 d0 204a 43c8 e000 c000
[13:07:53.505] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a043 8040 43c8 43c9 43c8 459 2440 43c8 808 284a 43c8 64c 2040 43c9 41c 2628 43c8 10c 2426 43c8 e000 c000
[13:07:57.216] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[13:07:57.216] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[13:07:57.219] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a188 80b1 4388 4388 14 2a48 438a 503 224f 4388 75a 2242 4388 309 204a 4388 255 2468 4388 4388 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a182 8000 43c8 2da 246a 43c8 54a 284e 43c8 40c 262c 43c9 43c8 43c9 2ca 224f 43c9 43c9 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a183 8040 43c8 43c9 43c8 43c9 65b 2848 43c8 65a 2a4a 43c8 43c8 43c9 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a184 80b1 43c8 74d 2666 43c8 cc 284e 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a185 80c0 4388 4388 7c 238d 823 4388 4388 d9 224a 4388 4388 4388 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a186 8000 4388 4388 4388 111 2646 4388 59 2a4e d2 204e 4388 51d 2465 4388 4388 4388 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a187 8040 4388 4388 4388 4388 4388 6cd 204a 4388 4388 4388 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a088 80b1 4388 4388 4388 35d 2462 4388 80d 2060 4388 4388 4388 4388 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a082 8000 43c8 43c8 43c8 40a 2a4e 43c9 43c8 55d 244f 43c8 685 2841 43c9 43c8 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a083 8040 43c8 43c9 43c8 651 2840 43c8 43c8 43c9 43c8 c9 224e 43c8 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a084 80b1 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a085 80c0 4388 4388 8f8 4388 24b 228a 4388 30a 246a 4388 4388 4388 e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a086 8000 4388 11a 2444 4388 4388 851 264e 4388 4388 4388 4388 4388 450 284a e000 c000
[13:07:57.219] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a087 8040 4388 618 2466 4388 4388 4388 24d 226c 4388 4388 4388 83 264f 4388 2 2a41 e000 c000
[13:08:01.356] INFO: PixTest:: pg_setup set to default.
[13:08:01.357] INFO: 12 hot pixels found in step 5
[13:08:02.348] INFO: Collecting data for 5 seconds...
[13:08:07.366] INFO: Done with hot pixel readout
[13:08:09.752] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[13:08:09.752] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a9 80c0 4388 4388 159 2442 2cd 2868 561 2a4e 4388 11d 224f 4388 445 2886 4388 11d 204e 4388 4388 4388 11b 2a4e 6cd 246a e000 c000
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a3 8040 43c8 43c9 43c8 43c8 43c8 43c9 43c8 43c8 704 244e e000 c000
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a4 80b1 43c8 43c8 43c8 6c8 202e 43c8 43c8 43c8 43c8 43c8 83 2662 e000 c000
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a5 80c0 43c8 288 244e 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a6 8000 5388 851 3254 c80 2015 43a 25fd 438 4388 11 2848 8b 2048 440 2666 4388 4388 213 226f 213 2662 812 2642 4388 e000 c000
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a7 8040 4388 4388 4388 481 2a4f 4388 4388 4388 4388 4388 4c 204a 41b 284f 41b 244b e000 c000
[13:08:09.752] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a8 80b1 4388 4388 4388 4388 24d 264f 4388 4388 2db 2443 4388 5a 204b 15a 2648 291 2865 4388 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a9 80c0 4388 4388 4d 284a 4389 4388 4388 493 244f 4388 152 2642 4388 4388 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a3 8040 43c8 43c9 43c8 43c9 43c8 43c8 43c8 43c9 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a4 80b1 43c8 494 224e 43c8 43c8 43c8 c 2440 43c8 43c8 43c8 43c8 148 2a45 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a5 80c0 43c8 43c8 43c8 43c8 43c8 559 2a2e 43c8 43c8 43c8 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a6 8000 5388 549 3600 5389 2654 2a0 2aa9 d5c 2402 a25 4388 4388 841 2642 85b 2662 4388 4388 4388 4388 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a7 8040 4388 699 2a4e 840 2a4f 859 264e 4388 4388 451 282e 4388 4388 4388 4388 4388 e000 c000
[13:08:09.753] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1a8 80b1 4388 4388 751 284b 438a 493 2a44 4388 244 2043 4388 718 2048 4388 4388 4388 e000 c000
[13:08:19.022] INFO: PixTest:: pg_setup set to default.
[13:08:19.023] INFO: 9 hot pixels found in step 6
[13:08:20.014] INFO: Collecting data for 5 seconds...
[13:08:25.032] INFO: Done with hot pixel readout
[13:08:36.688] INFO: PixTest:: pg_setup set to default.
[13:08:36.689] INFO: 12 hot pixels found in step 7
[13:08:37.680] INFO: Collecting data for 5 seconds...
[13:08:42.697] INFO: Done with hot pixel readout
[13:08:54.325] INFO: PixTest:: pg_setup set to default.
[13:08:54.326] INFO: 4 hot pixels found in step 8
[13:08:55.317] INFO: Collecting data for 5 seconds...
[13:09:00.334] INFO: Done with hot pixel readout
[13:09:11.944] INFO: PixTest:: pg_setup set to default.
[13:09:11.945] INFO: 7 hot pixels found in step 9
[13:09:12.937] INFO: Collecting data for 5 seconds...
[13:09:17.953] INFO: Done with hot pixel readout
[13:09:29.417] INFO: PixTest:: pg_setup set to default.
[13:09:29.417] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:09:29.418] INFO: 3 hot pixels found in step 10
[13:09:30.409] INFO: Collecting data for 5 seconds...
[13:09:35.427] INFO: Done with hot pixel readout
[13:09:46.975] INFO: PixTest:: pg_setup set to default.
[13:09:46.976] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:09:46.976] INFO: 1 hot pixels found in step 11
[13:09:47.012] INFO: 1 hot pixels could not be trimmed and have been masked.
[13:09:47.016] INFO: PixTest::trimHotPixels() done
[13:09:47.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C0.dat
[13:09:47.021] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C1.dat
[13:09:47.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C2.dat
[13:09:47.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C3.dat
[13:09:47.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C4.dat
[13:09:47.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C5.dat
[13:09:47.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C6.dat
[13:09:47.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C7.dat
[13:09:47.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C8.dat
[13:09:47.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C9.dat
[13:09:47.070] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C10.dat
[13:09:47.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C11.dat
[13:09:47.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C12.dat
[13:09:47.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C13.dat
[13:09:47.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C14.dat
[13:09:47.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C15.dat
[13:09:47.102] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//defaultMaskFile.dat
[13:09:47.111] INFO: enter test to run
[13:10:12.021] INFO: test: timing no parameter change
[13:10:12.021] INFO: running: timing
[13:10:12.024] INFO: ######################################################################
[13:10:12.024] INFO: PixTestTiming::doTest()
[13:10:12.024] INFO: ######################################################################
[13:10:12.024] INFO: ----------------------------------------------------------------------
[13:10:12.024] INFO: PixTestTiming::TBMPhaseScan()
[13:10:12.024] INFO: ----------------------------------------------------------------------
[13:17:36.328] INFO: TBM Phase Settings: 20
[13:17:36.328] INFO: 400MHz Phase: 5
[13:17:36.328] INFO: 160MHz Phase: 0
[13:17:36.328] INFO: Functional Phase Area: 3
[13:17:36.331] INFO: Test took 444307 ms.
[13:17:36.332] INFO: PixTestTiming::TBMPhaseScan() done.
[13:17:36.332] INFO: ----------------------------------------------------------------------
[13:17:36.332] INFO: PixTestTiming::ROCDelayScan()
[13:17:36.332] INFO: ----------------------------------------------------------------------
[13:20:12.264] INFO: ROC Delay Settings: 228
[13:20:12.264] INFO: ROC Header-Trailer/Token Delay: 11
[13:20:12.264] INFO: ROC Port 0 Delay: 4
[13:20:12.264] INFO: ROC Port 1 Delay: 4
[13:20:12.264] INFO: Functional ROC Area: 5
[13:20:12.267] INFO: Test took 155935 ms.
[13:20:12.267] INFO: PixTestTiming::ROCDelayScan() done.
[13:20:12.268] INFO: ----------------------------------------------------------------------
[13:20:12.268] INFO: PixTestTiming::TimingTest()
[13:20:12.268] INFO: ----------------------------------------------------------------------
[13:20:28.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:43.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:58.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:13.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:28.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:43.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:59.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:14.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:29.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:44.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:45.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:45.182] INFO: ----------------------------------------------------------------------
[13:22:45.182] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[13:22:45.183] INFO: ----------------------------------------------------------------------
[13:22:45.183] INFO: ----------------------------------------------------------------------
[13:22:45.183] INFO: Read back bit status: 1
[13:22:45.183] INFO: ----------------------------------------------------------------------
[13:22:45.183] INFO: ----------------------------------------------------------------------
[13:22:45.183] INFO: Timings are good!
[13:22:45.183] INFO: ----------------------------------------------------------------------
[13:22:45.183] INFO: Test took 152915 ms.
[13:22:45.183] INFO: PixTestTiming::TimingTest() done.
[13:22:45.183] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//tbmParameters_C0a.dat
[13:22:45.183] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:22:45.183] INFO: PixTestTiming::doTest took 753162 ms.
[13:22:45.183] INFO: PixTestTiming::doTest() done
[13:22:45.183] INFO: Write out TBMPhaseScan_0_V0
[13:22:45.183] INFO: Write out TBMPhaseScan_1_V0
[13:22:45.183] INFO: Write out CombinedTBMPhaseScan_V0
[13:22:45.184] INFO: Write out ROCDelayScan3_V0
[13:22:45.185] INFO: enter test to run
[13:23:16.351] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:23:16.351] INFO: running: highrate
[13:23:16.356] INFO: ----------------------------------------------------------------------
[13:23:16.356] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:23:16.356] INFO: ----------------------------------------------------------------------
[13:23:16.356] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:23:16.357] INFO: edge/corner pixel THR is adjusted
[13:23:16.357] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:23:17.313] INFO: Collecting data for 5 seconds...
[13:23:22.333] INFO: Done with hot pixel readout
[13:23:34.072] INFO: PixTest:: pg_setup set to default.
[13:23:34.073] INFO: 3 hot pixels found in step 0
[13:23:35.066] INFO: Collecting data for 5 seconds...
[13:23:40.084] INFO: Done with hot pixel readout
[13:23:51.729] INFO: PixTest:: pg_setup set to default.
[13:23:51.730] INFO: 3 hot pixels found in step 1
[13:23:52.722] INFO: Collecting data for 5 seconds...
[13:23:57.739] INFO: Done with hot pixel readout
[13:24:09.365] INFO: PixTest:: pg_setup set to default.
[13:24:09.365] INFO: 3 hot pixels found in step 2
[13:24:10.357] INFO: Collecting data for 5 seconds...
[13:24:15.375] INFO: Done with hot pixel readout
[13:24:27.025] INFO: PixTest:: pg_setup set to default.
[13:24:27.026] INFO: 3 hot pixels found in step 3
[13:24:28.018] INFO: Collecting data for 5 seconds...
[13:24:33.034] INFO: Done with hot pixel readout
[13:24:44.659] INFO: PixTest:: pg_setup set to default.
[13:24:44.660] INFO: 3 hot pixels found in step 4
[13:24:45.653] INFO: Collecting data for 5 seconds...
[13:24:50.671] INFO: Done with hot pixel readout
[13:25:02.364] INFO: PixTest:: pg_setup set to default.
[13:25:02.365] INFO: 3 hot pixels found in step 5
[13:25:03.357] INFO: Collecting data for 5 seconds...
[13:25:08.374] INFO: Done with hot pixel readout
[13:25:20.053] INFO: PixTest:: pg_setup set to default.
[13:25:20.054] INFO: 3 hot pixels found in step 6
[13:25:21.045] INFO: Collecting data for 5 seconds...
[13:25:26.062] INFO: Done with hot pixel readout
[13:25:37.732] INFO: PixTest:: pg_setup set to default.
[13:25:37.733] INFO: 4 hot pixels found in step 7
[13:25:38.725] INFO: Collecting data for 5 seconds...
[13:25:43.742] INFO: Done with hot pixel readout
[13:25:55.442] INFO: PixTest:: pg_setup set to default.
[13:25:55.443] INFO: 1 hot pixels found in step 8
[13:25:56.435] INFO: Collecting data for 5 seconds...
[13:26:01.451] INFO: Done with hot pixel readout
[13:26:13.108] INFO: PixTest:: pg_setup set to default.
[13:26:13.109] INFO: 2 hot pixels found in step 9
[13:26:14.101] INFO: Collecting data for 5 seconds...
[13:26:19.119] INFO: Done with hot pixel readout
[13:26:30.774] INFO: PixTest:: pg_setup set to default.
[13:26:30.775] INFO: 2 hot pixels found in step 10
[13:26:31.767] INFO: Collecting data for 5 seconds...
[13:26:36.784] INFO: Done with hot pixel readout
[13:26:48.412] INFO: PixTest:: pg_setup set to default.
[13:26:48.412] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:26:48.412] INFO: 2 hot pixels found in step 11
[13:26:49.404] INFO: Collecting data for 5 seconds...
[13:26:54.422] INFO: Done with hot pixel readout
[13:27:06.075] INFO: PixTest:: pg_setup set to default.
[13:27:06.075] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:27:06.076] INFO: 1 hot pixels found in step 12
[13:27:06.111] INFO: 1 hot pixels could not be trimmed and have been masked.
[13:27:06.115] INFO: PixTest::trimHotPixels() done
[13:27:06.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C0.dat
[13:27:06.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C1.dat
[13:27:06.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C2.dat
[13:27:06.133] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C3.dat
[13:27:06.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C4.dat
[13:27:06.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C5.dat
[13:27:06.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C6.dat
[13:27:06.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C7.dat
[13:27:06.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C8.dat
[13:27:06.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C9.dat
[13:27:06.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C10.dat
[13:27:06.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C11.dat
[13:27:06.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C12.dat
[13:27:06.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C13.dat
[13:27:06.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C14.dat
[13:27:06.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C15.dat
[13:27:06.202] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//defaultMaskFile.dat
[13:27:06.213] INFO: enter test to run
[13:27:40.477] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:27:40.477] INFO: running: highrate
[13:27:40.483] INFO: ----------------------------------------------------------------------
[13:27:40.483] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:27:40.483] INFO: ----------------------------------------------------------------------
[13:27:40.483] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:27:40.483] INFO: edge/corner pixel THR is adjusted
[13:27:40.483] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:27:41.441] INFO: Collecting data for 1 seconds...
[13:27:42.445] INFO: Done with hot pixel readout
[13:27:46.426] INFO: PixTest:: pg_setup set to default.
[13:27:46.427] INFO: 0 hot pixels found in step 0
[13:27:46.432] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:27:46.521] INFO: PixTest::trimHotPixels() done
[13:27:46.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C0.dat
[13:27:46.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C1.dat
[13:27:46.541] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C2.dat
[13:27:46.546] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C3.dat
[13:27:46.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C4.dat
[13:27:46.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C5.dat
[13:27:46.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C6.dat
[13:27:46.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C7.dat
[13:27:46.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C8.dat
[13:27:46.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C9.dat
[13:27:46.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C10.dat
[13:27:46.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C11.dat
[13:27:46.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C12.dat
[13:27:46.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C13.dat
[13:27:46.604] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C14.dat
[13:27:46.609] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//trimParameters35_C15.dat
[13:27:46.614] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-23_FPIXTest-17C-FNAL-160511-0909_2016-05-11_09h09m_1462975769/000_FPIXTest_p17//defaultMaskFile.dat
[13:27:46.624] INFO: enter test to run
[13:28:30.477] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:28:30.477] INFO: running: xray
[13:28:30.478] INFO: ----------------------------------------------------------------------
[13:28:30.478] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:28:30.478] INFO: ----------------------------------------------------------------------
[13:28:31.442] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:28:43.037] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:29:12.268] INFO: Resuming triggers.
[13:29:23.864] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:29:53.179] INFO: Resuming triggers.
[13:30:04.776] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:30:34.025] INFO: Resuming triggers.
[13:30:45.626] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:31:14.937] INFO: Resuming triggers.
[13:31:26.532] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:31:56.171] INFO: Resuming triggers.
[13:32:07.767] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:32:36.625] INFO: Resuming triggers.
[13:32:48.220] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:33:18.102] INFO: Resuming triggers.
[13:33:29.702] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:33:59.602] INFO: Resuming triggers.
[13:34:07.187] INFO: data taking finished, elapsed time: 100 seconds.
[13:34:26.898] INFO: PixTest:: pg_setup set to default.
[13:34:26.902] INFO: PixTestXray::doPhRun() done
[13:34:27.040] INFO: enter test to run
[13:35:26.522] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:35:26.522] INFO: running: xray
[13:35:26.523] INFO: ----------------------------------------------------------------------
[13:35:26.523] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:35:26.523] INFO: ----------------------------------------------------------------------
[13:35:27.487] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:35:34.221] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:36:04.322] INFO: Resuming triggers.
[13:36:11.062] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:36:41.235] INFO: Resuming triggers.
[13:36:47.975] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:37:18.015] INFO: Resuming triggers.
[13:37:24.748] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:37:54.884] INFO: Resuming triggers.
[13:38:01.619] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:38:31.795] INFO: Resuming triggers.
[13:38:38.532] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:39:08.627] INFO: Resuming triggers.
[13:39:15.361] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:39:45.486] INFO: Resuming triggers.
[13:39:52.226] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:40:22.297] INFO: Resuming triggers.
[13:40:29.030] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:40:59.182] INFO: Resuming triggers.
[13:41:05.915] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:41:36.023] INFO: Resuming triggers.
[13:41:42.761] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[13:42:12.946] INFO: Resuming triggers.
[13:42:19.685] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:42:50.310] INFO: Resuming triggers.
[13:42:57.049] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:43:27.784] INFO: Resuming triggers.
[13:43:34.517] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:44:04.899] INFO: Resuming triggers.
[13:44:10.941] INFO: data taking finished, elapsed time: 100 seconds.
[13:44:39.158] INFO: PixTest:: pg_setup set to default.
[13:44:39.161] INFO: PixTestXray::doPhRun() done
[13:44:39.313] INFO: enter test to run
[13:45:11.590] INFO: test: HighRate no parameter change
[13:45:11.590] INFO: running: highrate
[13:45:11.591] INFO: ----------------------------------------------------------------------
[13:45:11.591] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:45:11.591] INFO: ----------------------------------------------------------------------
[13:45:11.734] INFO: Expecting 768 events.
[13:45:12.869] INFO: 768 events read in total (419ms).
[13:45:12.869] INFO: Test took 1269ms.
[13:45:13.672] INFO: Expecting 41600 events.
[13:45:16.900] INFO: 41600 events read in total (2701ms).
[13:45:16.901] INFO: Test took 4026ms.
[13:45:16.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:17.653] INFO: Expecting 41600 events.
[13:45:20.852] INFO: 41600 events read in total (2672ms).
[13:45:20.853] INFO: Test took 3903ms.
[13:45:20.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:21.607] INFO: Expecting 41600 events.
[13:45:24.926] INFO: 41600 events read in total (2792ms).
[13:45:24.927] INFO: Test took 4023ms.
[13:45:24.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:25.688] INFO: Expecting 41600 events.
[13:45:28.911] INFO: 41600 events read in total (2696ms).
[13:45:28.912] INFO: Test took 3934ms.
[13:45:28.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:29.672] INFO: Expecting 41600 events.
[13:45:32.953] INFO: 41600 events read in total (2754ms).
[13:45:32.954] INFO: Test took 3990ms.
[13:45:32.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:33.714] INFO: Expecting 41600 events.
[13:45:36.949] INFO: 41600 events read in total (2708ms).
[13:45:36.950] INFO: Test took 3945ms.
[13:45:36.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:37.710] INFO: Expecting 41600 events.
[13:45:40.953] INFO: 41600 events read in total (2716ms).
[13:45:40.954] INFO: Test took 3954ms.
[13:45:40.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:41.712] INFO: Expecting 41600 events.
[13:45:44.941] INFO: 41600 events read in total (2702ms).
[13:45:44.942] INFO: Test took 3937ms.
[13:45:44.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:45.703] INFO: Expecting 41600 events.
[13:45:48.945] INFO: 41600 events read in total (2715ms).
[13:45:48.946] INFO: Test took 3955ms.
[13:45:48.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:49.703] INFO: Expecting 41600 events.
[13:45:52.943] INFO: 41600 events read in total (2713ms).
[13:45:52.944] INFO: Test took 3947ms.
[13:45:52.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:53.704] INFO: Expecting 41600 events.
[13:45:56.937] INFO: 41600 events read in total (2706ms).
[13:45:56.938] INFO: Test took 3945ms.
[13:45:56.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:57.694] INFO: Expecting 41600 events.
[13:46:00.922] INFO: 41600 events read in total (2701ms).
[13:46:00.923] INFO: Test took 3934ms.
[13:46:00.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:01.682] INFO: Expecting 41600 events.
[13:46:04.921] INFO: 41600 events read in total (2712ms).
[13:46:04.922] INFO: Test took 3948ms.
[13:46:04.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:05.684] INFO: Expecting 41600 events.
[13:46:08.917] INFO: 41600 events read in total (2706ms).
[13:46:08.918] INFO: Test took 3946ms.
[13:46:08.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:09.680] INFO: Expecting 41600 events.
[13:46:12.910] INFO: 41600 events read in total (2703ms).
[13:46:12.911] INFO: Test took 3941ms.
[13:46:12.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:13.669] INFO: Expecting 41600 events.
[13:46:16.908] INFO: 41600 events read in total (2712ms).
[13:46:16.909] INFO: Test took 3948ms.
[13:46:16.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:17.669] INFO: Expecting 41600 events.
[13:46:20.923] INFO: 41600 events read in total (2727ms).
[13:46:20.924] INFO: Test took 3964ms.
[13:46:20.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:21.679] INFO: Expecting 41600 events.
[13:46:24.914] INFO: 41600 events read in total (2708ms).
[13:46:24.915] INFO: Test took 3940ms.
[13:46:24.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:25.676] INFO: Expecting 41600 events.
[13:46:28.896] INFO: 41600 events read in total (2693ms).
[13:46:28.897] INFO: Test took 3930ms.
[13:46:28.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:29.659] INFO: Expecting 41600 events.
[13:46:32.742] INFO: 41600 events read in total (2556ms).
[13:46:32.743] INFO: Test took 3795ms.
[13:46:32.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:33.143] INFO: enter test to run
[13:46:42.229] INFO: test: HighRate no parameter change
[13:46:42.229] INFO: running: highrate
[13:46:42.230] INFO: ----------------------------------------------------------------------
[13:46:42.230] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:46:42.230] INFO: ----------------------------------------------------------------------
[13:46:42.846] INFO: Expecting 208000 events.
[13:46:54.687] INFO: 208000 events read in total (11315ms).
[13:46:54.690] INFO: Test took 12453ms.
[13:46:54.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:55.077] INFO: number of dead pixels (per ROC): 0 0 0 0 0 11 3 2 0 0 0 0 0 0 0 0
[13:46:55.077] INFO: number of red-efficiency pixels: 106 61 84 98 135 124 143 86 78 115 90 119 118 49 17 24
[13:46:55.077] INFO: number of X-ray hits detected: 68930 46802 67353 99973 108909 103136 105555 74655 72641 96484 90402 82295 83192 50059 20777 21103
[13:46:55.077] 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:46:55.077] INFO: number of Vcal hits detected: 207892 207930 207915 207901 207863 207286 207708 207816 207922 207883 207909 207880 207880 207951 207983 207975
[13:46:55.077] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0
[13:46:55.077] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 100.0 99.9 99.7 99.9 99.9 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0
[13:46:55.077] INFO: X-ray hit rate [MHz/cm2]: 20.2 13.7 19.7 29.3 31.9 30.2 30.9 21.9 21.3 28.3 26.5 24.1 24.4 14.7 6.1 6.2
[13:46:55.077] INFO: PixTestHighRate::doXPixelAlive() done
[13:46:55.125] INFO: PixTest:: pg_setup set to default.
[13:46:55.141] INFO: enter test to run
[13:47:19.029] INFO: test: HighRate no parameter change
[13:47:19.029] INFO: running: highrate
[13:47:19.030] INFO: ----------------------------------------------------------------------
[13:47:19.030] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:47:19.030] INFO: ----------------------------------------------------------------------
[13:47:19.642] INFO: Expecting 208000 events.
[13:47:33.219] INFO: 208000 events read in total (13050ms).
[13:47:33.224] INFO: Test took 14184ms.
[13:47:33.509] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:33.812] INFO: number of dead pixels (per ROC): 0 0 0 0 0 10 3 2 0 0 0 0 0 0 0 0
[13:47:33.812] INFO: number of red-efficiency pixels: 279 130 283 307 520 531 512 330 191 372 308 333 307 195 49 44
[13:47:33.812] INFO: number of X-ray hits detected: 146108 98575 142661 211822 229298 218136 224291 157426 154911 203938 192194 174702 176762 106548 44025 45657
[13:47:33.812] 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:47:33.812] INFO: number of Vcal hits detected: 207698 207853 207695 207662 207439 206841 207293 207554 207797 207610 207677 207646 207678 207794 207951 207956
[13:47:33.812] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.8 99.9 99.9 100.0 100.0
[13:47:33.812] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.4 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:47:33.812] INFO: X-ray hit rate [MHz/cm2]: 42.8 28.9 41.8 62.1 67.2 63.9 65.7 46.1 45.4 59.8 56.3 51.2 51.8 31.2 12.9 13.4
[13:47:33.812] INFO: PixTestHighRate::doXPixelAlive() done
[13:47:33.861] INFO: PixTest:: pg_setup set to default.
[13:47:33.879] INFO: enter test to run
[13:47:55.204] INFO: test: HighRate no parameter change
[13:47:55.204] INFO: running: highrate
[13:47:55.205] INFO: ----------------------------------------------------------------------
[13:47:55.206] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:47:55.206] INFO: ----------------------------------------------------------------------
[13:47:55.820] INFO: Expecting 208000 events.
[13:48:11.309] INFO: 208000 events read in total (14962ms).
[13:48:11.316] INFO: Test took 16100ms.
[13:48:11.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:12.103] INFO: number of dead pixels (per ROC): 0 0 0 0 0 10 3 2 0 0 0 0 0 0 0 0
[13:48:12.103] INFO: number of red-efficiency pixels: 640 266 680 796 1218 1126 1128 657 436 871 677 785 689 435 101 73
[13:48:12.103] INFO: number of X-ray hits detected: 221353 150742 216559 322596 349228 331038 341176 238511 236463 310811 291810 265634 267929 162818 67689 69615
[13:48:12.103] 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:48:12.103] INFO: number of Vcal hits detected: 207194 207676 207106 207078 206385 205955 206430 207096 207519 206954 207223 207077 207207 207495 207896 207923
[13:48:12.103] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.6 99.3 99.4 99.4 99.6 99.8 99.5 99.7 99.6 99.7 99.8 100.0 100.0
[13:48:12.103] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.6 99.6 99.2 99.0 99.2 99.6 99.8 99.5 99.6 99.6 99.6 99.8 100.0 100.0
[13:48:12.103] INFO: X-ray hit rate [MHz/cm2]: 64.9 44.2 63.5 94.6 102.4 97.0 100.0 69.9 69.3 91.1 85.5 77.9 78.5 47.7 19.8 20.4
[13:48:12.103] INFO: PixTestHighRate::doXPixelAlive() done
[13:48:12.149] INFO: PixTest:: pg_setup set to default.
[13:48:12.163] INFO: enter test to run
[13:48:14.852] INFO: test: exit no parameter change
[13:48:15.229] QUIET: Connection to board 33 closed.
[13:48:15.230] INFO: pXar: this is the end, my friend