[12:45:24.320] INFO: *** Welcome to pxar ***
[12:45:24.320] INFO: *** Today: 2016/06/28
[12:45:24.333] INFO: *** Version: v1.9.0-814-g7497
[12:45:24.333] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//dacParameters35_C15.dat
[12:45:24.362] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:45:24.363] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//defaultMaskFile.dat
[12:45:24.363] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C15.dat
[12:45:24.523] INFO: clk: 4
[12:45:24.523] INFO: ctr: 4
[12:45:24.523] INFO: sda: 19
[12:45:24.523] INFO: tin: 9
[12:45:24.523] INFO: level: 15
[12:45:24.523] INFO: triggerdelay: 0
[12:45:24.523] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:45:24.523] INFO: Log level: INFO
[12:45:24.540] QUIET: Connection to board DTB_WREK4U opened.
[12:45:24.543] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[12:45:24.546] INFO: RPC call hashes of host and DTB match: 398089610
[12:45:26.081] INFO: DUT info:
[12:45:26.081] INFO: The DUT currently contains the following objects:
[12:45:26.081] INFO: 2 TBM Cores tbm08c (2 ON)
[12:45:26.081] INFO: TBM Core alpha (0): 7 registers set
[12:45:26.081] INFO: TBM Core beta (1): 7 registers set
[12:45:26.081] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:45:26.081] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.081] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.081] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.081] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.081] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.081] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.081] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.082] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:45:26.485] INFO: enter 'restricted' command line mode
[12:45:26.485] INFO: enter test to run
[12:45:33.358] INFO: test: PixelAlive no parameter change
[12:45:33.358] INFO: running: pixelalive
[12:45:33.367] INFO: ----------------------------------------------------------------------
[12:45:33.367] 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:45:33.367] INFO: ----------------------------------------------------------------------
[12:45:33.692] INFO: Expecting 41600 events.
[12:45:38.076] INFO: 41600 events read in total (3666ms).
[12:45:38.240] INFO: Test took 4871ms.
[12:45:38.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:38.513] INFO: PixTestAlive::aliveTest() done
[12:45:38.513] INFO: number of dead pixels (per ROC): 0 0 0 8 0 3 0 0 0 0 0 0 0 0 0 0
[12:45:38.550] INFO: enter test to run
[12:45:56.150] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:45:56.150] INFO: running: highrate
[12:45:56.150] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:45:56.429] INFO: ----------------------------------------------------------------------
[12:45:56.429] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:45:56.429] INFO: ----------------------------------------------------------------------
[12:45:56.429] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:45:56.429] INFO: edge/corner pixel THR is adjusted
[12:45:56.429] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:45:57.387] INFO: Collecting data for 5 seconds...
[12:46:02.406] INFO: Done with hot pixel readout
[12:46:13.492] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (7) != Token Chain Length (8)
[12:46:13.492] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[12:46:13.492] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09f 8040 418a 418a 4188 418a 418a 54 2848 94 2449 50d 2245 418a 418a 45a 2262 54c 2a41 4188 e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a099 80c0 4388 4388 4388 4388 2d9 2069 4388 4d1 282d 4388 4388 4388 e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09a 8000 4388 4388 4388 4388 4388 4388 14 204b 4388 4388 1c 2449 e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09b 8040 4388 4388 4388 4388 4388 4388 4388 4388 e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09c 80b1 4388 4388 212 284e 4388 4388 314 2441 645 264f 4188 4188 4188 d58 2098 40 e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09d 80c0 4188 354 2220 4188 4188 4188 34d 224d 4188 4188 4188 40c 242a 84c 224c 4188 555 2049 e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09e 8000 4188 4188 61d 2665 418a 4188 4188 4188 4188 418a 4c 222d e000 c000
[12:46:13.492] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:13.492] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19f 8040 418a 418a 70c 2625 418a 418a 418a 690 2841 418a 418a 418a e000 c000
[12:46:13.493] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a199 80c0 4388 258 2246 4388 4388 4388 e0 2040 4388 4388 4388 4388 e000 c000
[12:46:13.493] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19a 8000 4388 4388 4388 4388 4388 4388 83 2241 21d 2040 4388 4388 e000 c000
[12:46:13.493] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19b 8040 4388 4388 4388 4388 4388 4388 4388 4388 e000 c000
[12:46:13.493] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19c 80b1 4388 d0 222d 250 2247 4388 d2 244a 4388 64a 282e 4188 4189 4188 4188 e000 c000
[12:46:13.493] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19d 80c0 4188 711 2266 4188 4188 4188 d1 222f 4188 4188 4188 4188 e000 c000
[12:46:13.493] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19e 8000 4188 715 206b 4188 4188 4c9 264f 4188 4188 4188 93 2043 4188 4188 e000 c000
[12:46:14.118] INFO: PixTest:: pg_setup set to default.
[12:46:14.119] INFO: 3 hot pixels found in step 0
[12:46:15.109] INFO: Collecting data for 5 seconds...
[12:46:20.126] INFO: Done with hot pixel readout
[12:46:21.488] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[12:46:21.488] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[12:46:21.488] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a093 8040 4388 4389 4388 4389 4388 4389 4388 4388 b 2046 28b 2665 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a08d 80c0 4188 4188 4188 4188 4188 4188 4188 4188 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a08e 8000 4188 4188 418a 4188 4188 4188 2cd 2249 4188 24c 2226 4c0 2a4d 418a e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a08f 8040 418a 255 2842 418a 4188 418a 418a 359 2880 418a 658 282d 418a 4188 70a 2a64 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a090 80b0 f08 2495 444 4388 4388 4388 4388 4388 4388 4389 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a091 80c0 4388 4388 4389 d9 2041 4388 4389 294 2a2f 4389 858 2041 4389 80a 2880 4389 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a092 8000 4388 218 2828 4388 4388 4389 4388 70b 2840 4388 a0 282c 345 2664 4389 488 2640 842 224f 4389 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a193 8040 4388 4389 4388 4389 22 2849 4388 4389 4388 4389 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a18d 80c0 4188 4188 4188 d9 2a4c 4188 4188 4188 4188 4188 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a18e 8000 4188 4188 4188 85c 2229 4188 4188 4188 4188 4188 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a18f 8040 418a 84c 2a45 418a 418a 418a 418a 418a 418a 418a e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a190 80b0 704 4389 4389 4389 4389 4389 4389 4389 e000 c000
[12:46:21.488] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a191 80c0 4388 4388 4388 849 2445 4388 4389 4389 4389 4389 e000 c000
[12:46:21.489] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a192 8000 4388 6ca 286a 4388 4389 512 2662 60b 284f 4389 143 242f 4388 121 224e 4388 4389 4389 298 2825 e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c1 80c0 4188 4188 4189 4188 4189 4189 4189 4189 e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0bb 8040 4388 58 240d 4388 4388 85a 2641 4388 4388 4388 4388 4388 e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0bc 80b1 4388 4388 4388 314 2829 4388 4388 4388 300 2429 649 224f 4388 4388 e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0bd 80c0 4388 4388 4388 4388 4388 858 2a43 4388 4388 4388 88 2a41 e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0be 8000 4388 4388 1b 2029 438a 555 222a 65b 2867 742 222d 742 262c 4388 64a 202c 5188 4188 645 21bf 4188 15c 282d 418a e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0bf 8040 418a 418a 4188 418a 418a 418a 418a 4188 31b 2263 6a0 2248 e000 c000
[12:46:23.093] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c0 80b1 4188 4188 4188 4188 4188 612 2645 4188 4188 41c 2827 4189 515 2640 e000 c000
[12:46:26.087] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 has NoTokenPass but 8 ROCs were found
[12:46:26.087] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a9 80c0 4388 4388 4388 4388 4388 4388 4388 4388 e000 c000
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a3 8040 4188 4189 4188 4189 4188 508 2827 50c 2a4d 4189 4188 4188 e000 c000
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a4 80b1 4188 4188 d8 282f 4188 4188 e1 264f 4188 4188 4188 d 2442 4188 e000 c000
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a5 80c0 4188 4188 15d 224d 4188 304 2024 4188 343 2468 518 2845 4188 48c 2829 4188 4188 4188 60b 2465 e000 c000
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a0a6 8000 4188 4188 4188 4188 54c 202c 4188 75c 222d 4188 4188 2c9 2a42 701 2a45 4388 6a0 2116 83e 2000 ff 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
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a7 8040 4388 15d 2a44 4388 4b 2247 4388 4388 4388 4388 5d 284d 91 2464 315 204f 358 284f 4388 4388 e000 c000
[12:46:26.087] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0a8 80b1 4388 418 262c 4388 4388 4388 241 284d 4388 4388 4388 4388 e000 c000
[12:46:31.675] INFO: PixTest:: pg_setup set to default.
[12:46:31.676] INFO: 2 hot pixels found in step 1
[12:46:32.666] INFO: Collecting data for 5 seconds...
[12:46:37.683] INFO: Done with hot pixel readout
[12:46:40.998] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[12:46:40.998] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[12:46:40.998] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ca 8000 4388 4388 4388 6c2 2840 852 2249 4388 4388 512 2044 851 2247 4388 4388 2d3 224c 4388 5b 2844 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c4 80b1 4188 51a 282c 4188 4188 4188 4188 4188 245 2849 4188 4188 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c5 80c0 4188 4188 212 284d 722 204d 4188 4188 4188 4188 4188 4188 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c6 8000 4188 4188 4188 822 244c 4188 4188 4188 320 2245 4188 4188 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c7 8040 4188 4188 821 224f 4388 7e9 2558 285 2661 4388 4388 4388 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c8 80b1 4388 4388 4388 861 224e 4388 511 2a4b 4388 4388 285 2040 30b 2a61 404 2044 4388 4388 6dc 2849 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c9 80c0 4388 4388 4388 750 2829 4388 4388 4388 4388 854 2641 4388 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ca 8000 4388 141 2069 4388 4388 358 2849 4388 4388 4388 4388 4388 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c4 80b1 4188 352 2448 352 264f 4188 4188 4188 4188 4188 4188 4188 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c5 80c0 4188 4188 4188 4188 4188 4188 4188 4188 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c6 8000 4188 4188 84d 2660 4188 4188 9 284c 4188 4188 4188 4188 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c7 8040 4188 4188 4388 4388 852 222a 254 4388 4388 4388 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c8 80b1 4388 4388 ca 2423 4388 4388 4388 118 2625 4388 4388 4388 e000 c000
[12:46:40.998] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c9 80c0 4388 4388 4388 4388 4388 43 2a46 4388 4388 4388 e000 c000
[12:46:44.009] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[12:46:44.009] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b2 8000 4188 4188 4188 64b 284f 4189 4188 4188 4189 4189 e000 c000
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ac 80b1 4388 4388 4388 4388 4388 159 2242 4388 805 2228 4388 4388 e000 c000
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ad 80c0 4388 4388 4388 412 2a27 4388 10 2843 4388 4388 4388 814 2a4f 4388 e000 c000
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ae 8000 4388 4388 438a 4388 4388 359 2244 4388 4388 438a e000 c000
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0af 9040 418a 1b 2a4a 418a 4188 402 260f 418a 5b 2043 288 2045 418a 418a 208 2249 441 2665 418a 4188 313 284f e000 c000
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b0 80b1 4188 358 222f 4188 4188 4188 4188 4188 4ca 2247 4188 4189 e000 c000
[12:46:44.009] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b1 80c0 4188 4188 152 264d 4189 4188 4189 c5 2a4c 4189 1a 244d 14a 282c 14a 2429 4189 28a 206b 4189 e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b2 8000 4188 4188 503 2a45 4189 65a 224c 4189 4188 4188 4189 51b 2449 4189 e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ac 80b1 4388 4388 4388 4388 545 284f 4388 4388 30b 2841 4388 4388 e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ad 80c0 4388 4388 4388 c9 2882 360 2248 4388 4388 4388 c9 2844 49a 284f 4388 4388 e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ae 8000 4388 4388 4388 55b 204f 55b 2269 4388 4388 4388 4388 4388 e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1af 9040 418a 48b 224e 418a 418a 75b 2441 418a 418a 418a 418a e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b0 80b1 4189 4189 60a 2643 65c 2a46 4189 4189 4189 4189 4189 48d 2065 4189 25c 2642 341 222f e000 c000
[12:46:44.010] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b1 80c0 4188 352 226c 4188 4188 4188 4189 6a1 248f 4189 4189 4189 e000 c000
[12:46:49.255] INFO: PixTest:: pg_setup set to default.
[12:46:49.255] INFO: 2 hot pixels found in step 2
[12:46:50.246] INFO: Collecting data for 5 seconds...
[12:46:55.264] INFO: Done with hot pixel readout
[12:47:06.812] INFO: PixTest:: pg_setup set to default.
[12:47:06.813] INFO: 0 hot pixels found in step 3
[12:47:06.847] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:47:06.851] INFO: PixTest::trimHotPixels() done
[12:47:06.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C0.dat
[12:47:06.857] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C1.dat
[12:47:06.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C2.dat
[12:47:06.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C3.dat
[12:47:06.874] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C4.dat
[12:47:06.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C5.dat
[12:47:06.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C6.dat
[12:47:06.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C7.dat
[12:47:06.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C8.dat
[12:47:06.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C9.dat
[12:47:06.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C10.dat
[12:47:06.911] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C11.dat
[12:47:06.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C12.dat
[12:47:06.922] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C13.dat
[12:47:06.927] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C14.dat
[12:47:06.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C15.dat
[12:47:06.938] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//defaultMaskFile.dat
[12:47:06.947] INFO: enter test to run
[12:47:39.668] INFO: test: timing no parameter change
[12:47:39.668] INFO: running: timing
[12:47:39.672] INFO: ######################################################################
[12:47:39.672] INFO: PixTestTiming::doTest()
[12:47:39.672] INFO: ######################################################################
[12:47:39.672] INFO: ----------------------------------------------------------------------
[12:47:39.672] INFO: PixTestTiming::TBMPhaseScan()
[12:47:39.672] INFO: ----------------------------------------------------------------------
[12:52:14.163] INFO: TBM Phase Settings: 248
[12:52:14.163] INFO: 400MHz Phase: 6
[12:52:14.163] INFO: 160MHz Phase: 7
[12:52:14.163] INFO: Functional Phase Area: 3
[12:52:14.166] INFO: Test took 274494 ms.
[12:52:14.166] INFO: PixTestTiming::TBMPhaseScan() done.
[12:52:14.167] INFO: ----------------------------------------------------------------------
[12:52:14.167] INFO: PixTestTiming::ROCDelayScan()
[12:52:14.167] INFO: ----------------------------------------------------------------------
[12:54:23.492] INFO: ROC Delay Settings: 227
[12:54:23.492] INFO: ROC Header-Trailer/Token Delay: 11
[12:54:23.492] INFO: ROC Port 0 Delay: 3
[12:54:23.492] INFO: ROC Port 1 Delay: 4
[12:54:23.492] INFO: Functional ROC Area: 3
[12:54:23.496] INFO: Test took 129330 ms.
[12:54:23.496] INFO: PixTestTiming::ROCDelayScan() done.
[12:54:23.496] INFO: ----------------------------------------------------------------------
[12:54:23.496] INFO: PixTestTiming::TimingTest()
[12:54:23.496] INFO: ----------------------------------------------------------------------
[12:54:39.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:54.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:09.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:24.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:40.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:55.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:10.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:25.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:40.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:55.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:56.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:56.306] INFO: ----------------------------------------------------------------------
[12:56:56.306] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:56:56.306] INFO: ----------------------------------------------------------------------
[12:56:56.306] INFO: ----------------------------------------------------------------------
[12:56:56.306] INFO: Read back bit status: 1
[12:56:56.306] INFO: ----------------------------------------------------------------------
[12:56:56.306] INFO: ----------------------------------------------------------------------
[12:56:56.306] INFO: Timings are good!
[12:56:56.306] INFO: ----------------------------------------------------------------------
[12:56:56.306] INFO: Test took 152810 ms.
[12:56:56.306] INFO: PixTestTiming::TimingTest() done.
[12:56:56.306] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:56:56.306] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:56:56.306] INFO: PixTestTiming::doTest took 556637 ms.
[12:56:56.306] INFO: PixTestTiming::doTest() done
[12:56:56.306] INFO: Write out TBMPhaseScan_0_V0
[12:56:56.307] INFO: Write out TBMPhaseScan_1_V0
[12:56:56.307] INFO: Write out CombinedTBMPhaseScan_V0
[12:56:56.308] INFO: Write out ROCDelayScan3_V0
[12:56:56.308] INFO: enter test to run
[12:57:46.080] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:57:46.081] INFO: running: highrate
[12:57:46.085] INFO: ----------------------------------------------------------------------
[12:57:46.086] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:57:46.086] INFO: ----------------------------------------------------------------------
[12:57:46.086] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:57:46.086] INFO: edge/corner pixel THR is adjusted
[12:57:46.086] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:57:47.042] INFO: Collecting data for 5 seconds...
[12:57:52.064] INFO: Done with hot pixel readout
[12:58:03.850] INFO: PixTest:: pg_setup set to default.
[12:58:03.851] INFO: 1 hot pixels found in step 0
[12:58:04.841] INFO: Collecting data for 5 seconds...
[12:58:09.860] INFO: Done with hot pixel readout
[12:58:21.628] INFO: PixTest:: pg_setup set to default.
[12:58:21.629] INFO: 0 hot pixels found in step 1
[12:58:21.663] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:58:21.667] INFO: PixTest::trimHotPixels() done
[12:58:21.667] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C0.dat
[12:58:21.672] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C1.dat
[12:58:21.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C2.dat
[12:58:21.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C3.dat
[12:58:21.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C4.dat
[12:58:21.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C5.dat
[12:58:21.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C6.dat
[12:58:21.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C7.dat
[12:58:21.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C8.dat
[12:58:21.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C9.dat
[12:58:21.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C10.dat
[12:58:21.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C11.dat
[12:58:21.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C12.dat
[12:58:21.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C13.dat
[12:58:21.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C14.dat
[12:58:21.748] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C15.dat
[12:58:21.754] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//defaultMaskFile.dat
[12:58:21.765] INFO: enter test to run
[12:59:11.480] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:59:11.480] INFO: running: highrate
[12:59:11.485] INFO: ----------------------------------------------------------------------
[12:59:11.485] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:59:11.485] INFO: ----------------------------------------------------------------------
[12:59:11.485] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:59:11.485] INFO: edge/corner pixel THR is adjusted
[12:59:11.485] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:59:12.442] INFO: Collecting data for 1 seconds...
[12:59:13.447] INFO: Done with hot pixel readout
[12:59:17.289] INFO: PixTest:: pg_setup set to default.
[12:59:17.290] INFO: 0 hot pixels found in step 0
[12:59:17.296] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:59:17.392] INFO: PixTest::trimHotPixels() done
[12:59:17.392] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C0.dat
[12:59:17.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C1.dat
[12:59:17.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C2.dat
[12:59:17.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C3.dat
[12:59:17.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C4.dat
[12:59:17.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C5.dat
[12:59:17.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C6.dat
[12:59:17.434] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C7.dat
[12:59:17.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C8.dat
[12:59:17.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C9.dat
[12:59:17.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C10.dat
[12:59:17.456] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C11.dat
[12:59:17.461] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C12.dat
[12:59:17.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C13.dat
[12:59:17.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C14.dat
[12:59:17.477] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//trimParameters35_C15.dat
[12:59:17.482] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-44_FPIXTest-17C-FNAL-160616-0922_2016-06-16_09h22m_1466086927/000_FPIXTest_p17//defaultMaskFile.dat
[12:59:17.493] INFO: enter test to run
[12:59:48.744] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:59:48.744] INFO: running: xray
[12:59:48.745] INFO: ----------------------------------------------------------------------
[12:59:48.745] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:59:48.745] INFO: ----------------------------------------------------------------------
[12:59:49.707] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:00:01.570] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:00:30.861] INFO: Resuming triggers.
[13:00:42.728] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:01:11.921] INFO: Resuming triggers.
[13:01:23.788] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:01:52.968] INFO: Resuming triggers.
[13:02:04.834] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:02:34.087] INFO: Resuming triggers.
[13:02:45.953] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:03:15.306] INFO: Resuming triggers.
[13:03:27.171] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:03:56.484] INFO: Resuming triggers.
[13:04:08.350] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:04:37.651] INFO: Resuming triggers.
[13:04:49.514] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:05:18.753] INFO: Resuming triggers.
[13:05:24.159] INFO: data taking finished, elapsed time: 100 seconds.
[13:05:37.824] INFO: PixTest:: pg_setup set to default.
[13:05:37.827] INFO: PixTestXray::doPhRun() done
[13:05:37.989] INFO: enter test to run
[13:06:21.957] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:06:21.957] INFO: running: xray
[13:06:21.958] INFO: ----------------------------------------------------------------------
[13:06:21.958] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:06:21.958] INFO: ----------------------------------------------------------------------
[13:06:22.922] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:06:30.096] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:07:00.746] INFO: Resuming triggers.
[13:07:07.920] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[13:07:38.717] INFO: Resuming triggers.
[13:07:45.890] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:08:16.776] INFO: Resuming triggers.
[13:08:23.949] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[13:08:54.996] INFO: Resuming triggers.
[13:09:02.171] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:09:33.261] INFO: Resuming triggers.
[13:09:40.435] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:10:10.632] INFO: Resuming triggers.
[13:10:17.808] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:10:47.722] INFO: Resuming triggers.
[13:10:54.901] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:11:24.001] INFO: Resuming triggers.
[13:11:32.177] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:12:02.216] INFO: Resuming triggers.
[13:12:09.393] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:12:39.516] INFO: Resuming triggers.
[13:12:46.691] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:13:16.811] INFO: Resuming triggers.
[13:13:23.987] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:13:54.254] INFO: Resuming triggers.
[13:14:01.426] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:14:31.522] INFO: Resuming triggers.
[13:14:38.599] INFO: data taking finished, elapsed time: 100 seconds.
[13:15:07.279] INFO: PixTest:: pg_setup set to default.
[13:15:07.282] INFO: PixTestXray::doPhRun() done
[13:15:07.429] INFO: enter test to run
[13:15:47.441] INFO: test: HighRate no parameter change
[13:15:47.441] INFO: running: highrate
[13:15:47.452] INFO: ----------------------------------------------------------------------
[13:15:47.452] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:15:47.452] INFO: ----------------------------------------------------------------------
[13:15:47.608] INFO: Expecting 768 events.
[13:15:48.742] INFO: 768 events read in total (418ms).
[13:15:48.743] INFO: Test took 1270ms.
[13:15:49.546] INFO: Expecting 41600 events.
[13:15:52.258] INFO: 41600 events read in total (2185ms).
[13:15:52.259] INFO: Test took 3510ms.
[13:15:52.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:53.025] INFO: Expecting 41600 events.
[13:15:56.101] INFO: 41600 events read in total (2549ms).
[13:15:56.102] INFO: Test took 3793ms.
[13:15:56.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:56.867] INFO: Expecting 41600 events.
[13:16:00.058] INFO: 41600 events read in total (2664ms).
[13:16:00.059] INFO: Test took 3908ms.
[13:16:00.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:00.816] INFO: Expecting 41600 events.
[13:16:04.004] INFO: 41600 events read in total (2661ms).
[13:16:04.005] INFO: Test took 3899ms.
[13:16:04.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:04.762] INFO: Expecting 41600 events.
[13:16:07.954] INFO: 41600 events read in total (2665ms).
[13:16:07.955] INFO: Test took 3901ms.
[13:16:07.986] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:08.715] INFO: Expecting 41600 events.
[13:16:11.744] INFO: 41600 events read in total (2502ms).
[13:16:11.745] INFO: Test took 3742ms.
[13:16:11.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:12.504] INFO: Expecting 41600 events.
[13:16:15.728] INFO: 41600 events read in total (2697ms).
[13:16:15.729] INFO: Test took 3935ms.
[13:16:15.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:16.488] INFO: Expecting 41600 events.
[13:16:19.699] INFO: 41600 events read in total (2684ms).
[13:16:19.700] INFO: Test took 3923ms.
[13:16:19.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:20.458] INFO: Expecting 41600 events.
[13:16:23.284] INFO: 41600 events read in total (2299ms).
[13:16:23.285] INFO: Test took 3536ms.
[13:16:23.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:24.046] INFO: Expecting 41600 events.
[13:16:27.236] INFO: 41600 events read in total (2663ms).
[13:16:27.237] INFO: Test took 3902ms.
[13:16:27.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:27.996] INFO: Expecting 41600 events.
[13:16:31.169] INFO: 41600 events read in total (2647ms).
[13:16:31.170] INFO: Test took 3885ms.
[13:16:31.212] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:31.920] INFO: Expecting 41600 events.
[13:16:35.158] INFO: 41600 events read in total (2711ms).
[13:16:35.159] INFO: Test took 3930ms.
[13:16:35.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:35.919] INFO: Expecting 41600 events.
[13:16:39.151] INFO: 41600 events read in total (2705ms).
[13:16:39.152] INFO: Test took 3944ms.
[13:16:39.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:39.910] INFO: Expecting 41600 events.
[13:16:43.141] INFO: 41600 events read in total (2704ms).
[13:16:43.142] INFO: Test took 3942ms.
[13:16:43.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:43.904] INFO: Expecting 41600 events.
[13:16:47.095] INFO: 41600 events read in total (2664ms).
[13:16:47.096] INFO: Test took 3905ms.
[13:16:47.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:47.853] INFO: Expecting 41600 events.
[13:16:51.094] INFO: 41600 events read in total (2714ms).
[13:16:51.095] INFO: Test took 3948ms.
[13:16:51.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:51.858] INFO: Expecting 41600 events.
[13:16:55.101] INFO: 41600 events read in total (2716ms).
[13:16:55.102] INFO: Test took 3958ms.
[13:16:55.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:55.861] INFO: Expecting 41600 events.
[13:16:59.085] INFO: 41600 events read in total (2697ms).
[13:16:59.086] INFO: Test took 3934ms.
[13:16:59.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:59.847] INFO: Expecting 41600 events.
[13:17:03.035] INFO: 41600 events read in total (2661ms).
[13:17:03.036] INFO: Test took 3903ms.
[13:17:03.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:03.793] INFO: Expecting 41600 events.
[13:17:06.843] INFO: 41600 events read in total (2523ms).
[13:17:06.844] INFO: Test took 3758ms.
[13:17:06.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:07.239] INFO: enter test to run
[13:17:15.009] INFO: test: HighRate no parameter change
[13:17:15.009] INFO: running: highrate
[13:17:15.010] INFO: ----------------------------------------------------------------------
[13:17:15.010] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:17:15.010] INFO: ----------------------------------------------------------------------
[13:17:15.631] INFO: Expecting 208000 events.
[13:17:27.193] INFO: 208000 events read in total (11035ms).
[13:17:27.196] INFO: Test took 12180ms.
[13:17:27.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:27.574] INFO: number of dead pixels (per ROC): 0 0 0 6 0 3 0 0 0 0 0 0 0 0 0 0
[13:17:27.574] INFO: number of red-efficiency pixels: 70 34 67 107 120 139 136 86 86 126 103 83 80 66 22 16
[13:17:27.574] INFO: number of X-ray hits detected: 55909 38866 60597 97289 101487 108556 101809 74805 68597 87611 84749 70360 74652 44632 20132 24504
[13:17:27.574] 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:17:27.574] INFO: number of Vcal hits detected: 207930 207966 207931 207597 207876 207710 207860 207914 207910 207874 207893 207917 207917 207934 207978 207984
[13:17:27.574] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[13:17:27.574] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.8 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:17:27.574] INFO: X-ray hit rate [MHz/cm2]: 16.4 11.4 17.8 28.5 29.7 31.8 29.8 21.9 20.1 25.7 24.8 20.6 21.9 13.1 5.9 7.2
[13:17:27.574] INFO: PixTestHighRate::doXPixelAlive() done
[13:17:27.625] INFO: PixTest:: pg_setup set to default.
[13:17:27.640] INFO: enter test to run
[13:17:53.736] INFO: test: HighRate no parameter change
[13:17:53.736] INFO: running: highrate
[13:17:53.737] INFO: ----------------------------------------------------------------------
[13:17:53.737] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:17:53.737] INFO: ----------------------------------------------------------------------
[13:17:54.356] INFO: Expecting 208000 events.
[13:18:07.923] INFO: 208000 events read in total (13040ms).
[13:18:07.928] INFO: Test took 14180ms.
[13:18:08.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:08.497] INFO: number of dead pixels (per ROC): 0 0 0 6 0 3 0 0 0 0 0 0 0 0 0 0
[13:18:08.497] INFO: number of red-efficiency pixels: 123 118 177 402 381 450 378 301 242 340 278 207 228 140 42 67
[13:18:08.497] INFO: number of X-ray hits detected: 115461 80400 124741 200231 209027 223735 210030 154388 141810 181203 174517 144200 155381 92541 41721 51124
[13:18:08.497] 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:18:08.497] INFO: number of Vcal hits detected: 207874 207878 207818 207278 207591 207367 207599 207673 207751 207646 207711 207786 207761 207848 207957 207931
[13:18:08.497] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[13:18:08.497] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[13:18:08.497] INFO: X-ray hit rate [MHz/cm2]: 33.8 23.6 36.6 58.7 61.3 65.6 61.6 45.3 41.6 53.1 51.2 42.3 45.5 27.1 12.2 15.0
[13:18:08.497] INFO: PixTestHighRate::doXPixelAlive() done
[13:18:08.545] INFO: PixTest:: pg_setup set to default.
[13:18:08.568] INFO: enter test to run
[13:19:00.744] INFO: test: HighRate no parameter change
[13:19:00.744] INFO: running: highrate
[13:19:00.745] INFO: ----------------------------------------------------------------------
[13:19:00.745] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:19:00.745] INFO: ----------------------------------------------------------------------
[13:19:01.367] INFO: Expecting 208000 events.
[13:19:16.060] INFO: 208000 events read in total (14166ms).
[13:19:16.066] INFO: Test took 15311ms.
[13:19:16.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:16.806] INFO: number of dead pixels (per ROC): 0 0 0 6 0 3 0 0 0 0 0 0 0 0 0 0
[13:19:16.806] INFO: number of red-efficiency pixels: 288 225 389 917 977 1133 942 650 471 759 680 483 538 354 88 115
[13:19:16.806] INFO: number of X-ray hits detected: 174802 121883 189183 305190 316225 337572 317335 233688 215283 275047 265403 218943 234724 141025 62983 77712
[13:19:16.806] 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:19:16.806] INFO: number of Vcal hits detected: 207677 207764 207557 206593 206832 206433 206861 207191 207482 207133 207236 207474 207403 207598 207910 207883
[13:19:16.807] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.5 99.5 99.4 99.5 99.7 99.8 99.6 99.7 99.8 99.7 99.8 100.0 99.9
[13:19:16.807] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.3 99.4 99.2 99.5 99.6 99.8 99.6 99.6 99.7 99.7 99.8 100.0 99.9
[13:19:16.807] INFO: X-ray hit rate [MHz/cm2]: 51.2 35.7 55.5 89.5 92.7 98.9 93.0 68.5 63.1 80.6 77.8 64.2 68.8 41.3 18.5 22.8
[13:19:16.807] INFO: PixTestHighRate::doXPixelAlive() done
[13:19:16.852] INFO: PixTest:: pg_setup set to default.
[13:19:16.872] INFO: enter test to run
[13:19:54.247] INFO: test: exit no parameter change
[13:19:54.677] QUIET: Connection to board 32 closed.
[13:19:54.690] INFO: pXar: this is the end, my friend