[13:47:08.896] INFO: *** Welcome to pxar ***
[13:47:08.896] INFO: *** Today: 2016/05/31
[13:47:08.917] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:47:08.917] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//dacParameters35_C15.dat
[13:47:08.980] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:47:08.980] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//defaultMaskFile.dat
[13:47:08.985] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C15.dat
[13:47:09.140] INFO: clk: 4
[13:47:09.140] INFO: ctr: 4
[13:47:09.140] INFO: sda: 19
[13:47:09.140] INFO: tin: 9
[13:47:09.140] INFO: level: 15
[13:47:09.140] INFO: triggerdelay: 0
[13:47:09.140] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:47:09.140] INFO: Log level: INFO
[13:47:09.158] QUIET: Connection to board DTB_WREKRL opened.
[13:47:09.162] 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:47:09.165] INFO: RPC call hashes of host and DTB match: 398089610
[13:47:10.692] INFO: DUT info:
[13:47:10.692] INFO: The DUT currently contains the following objects:
[13:47:10.692] INFO: 2 TBM Cores tbm08c (2 ON)
[13:47:10.692] INFO: TBM Core alpha (0): 7 registers set
[13:47:10.692] INFO: TBM Core beta (1): 7 registers set
[13:47:10.692] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:47:10.692] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.692] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.692] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.692] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:10.693] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:11.097] INFO: enter 'restricted' command line mode
[13:47:11.097] INFO: enter test to run
[13:47:21.348] INFO: test: PixelAlive no parameter change
[13:47:21.348] INFO: running: pixelalive
[13:47:21.357] INFO: ----------------------------------------------------------------------
[13:47:21.357] 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:47:21.357] INFO: ----------------------------------------------------------------------
[13:47:21.677] INFO: Expecting 41600 events.
[13:47:25.956] INFO: 41600 events read in total (3561ms).
[13:47:26.125] INFO: Test took 4765ms.
[13:47:26.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:26.403] INFO: PixTestAlive::aliveTest() done
[13:47:26.403] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:47:26.433] INFO: enter test to run
[13:47:52.180] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:47:52.180] INFO: running: highrate
[13:47:52.180] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:47:52.386] INFO: ----------------------------------------------------------------------
[13:47:52.386] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:47:52.386] INFO: ----------------------------------------------------------------------
[13:47:52.386] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:47:52.386] INFO: edge/corner pixel THR is adjusted
[13:47:52.386] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:47:53.345] INFO: Collecting data for 5 seconds...
[13:47:58.361] INFO: Done with hot pixel readout
[13:48:09.816] INFO: PixTest:: pg_setup set to default.
[13:48:09.817] INFO: 0 hot pixels found in step 0
[13:48:09.829] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:48:09.833] INFO: PixTest::trimHotPixels() done
[13:48:09.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C0.dat
[13:48:09.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C1.dat
[13:48:09.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C2.dat
[13:48:09.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C3.dat
[13:48:09.874] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C4.dat
[13:48:09.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C5.dat
[13:48:09.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C6.dat
[13:48:09.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C7.dat
[13:48:09.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C8.dat
[13:48:09.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C9.dat
[13:48:09.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C10.dat
[13:48:09.911] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C11.dat
[13:48:09.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C12.dat
[13:48:09.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C13.dat
[13:48:09.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C14.dat
[13:48:09.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C15.dat
[13:48:09.937] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//defaultMaskFile.dat
[13:48:09.947] INFO: enter test to run
[13:49:27.699] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:49:27.699] INFO: running: highrate
[13:49:27.704] INFO: ----------------------------------------------------------------------
[13:49:27.704] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:49:27.704] INFO: ----------------------------------------------------------------------
[13:49:27.704] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:49:27.704] INFO: edge/corner pixel THR is adjusted
[13:49:27.704] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:49:28.662] INFO: Collecting data for 1 seconds...
[13:49:29.665] INFO: Done with hot pixel readout
[13:49:33.604] INFO: PixTest:: pg_setup set to default.
[13:49:33.605] INFO: 0 hot pixels found in step 0
[13:49:33.610] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:49:33.704] INFO: PixTest::trimHotPixels() done
[13:49:33.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C0.dat
[13:49:33.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C1.dat
[13:49:33.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C2.dat
[13:49:33.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C3.dat
[13:49:33.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C4.dat
[13:49:33.737] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C5.dat
[13:49:33.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C6.dat
[13:49:33.748] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C7.dat
[13:49:33.753] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C8.dat
[13:49:33.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C9.dat
[13:49:33.764] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C10.dat
[13:49:33.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C11.dat
[13:49:33.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C12.dat
[13:49:33.779] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C13.dat
[13:49:33.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C14.dat
[13:49:33.790] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C15.dat
[13:49:33.795] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//defaultMaskFile.dat
[13:49:33.805] INFO: enter test to run
[13:50:05.011] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:50:05.011] INFO: running: xray
[13:50:05.012] INFO: ----------------------------------------------------------------------
[13:50:05.012] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:50:05.012] INFO: ----------------------------------------------------------------------
[13:50:05.975] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:50:17.659] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:50:46.864] INFO: Resuming triggers.
[13:50:58.550] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:51:27.909] INFO: Resuming triggers.
[13:51:39.596] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:52:08.882] INFO: Resuming triggers.
[13:52:20.566] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:52:49.898] INFO: Resuming triggers.
[13:53:01.586] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:53:30.848] INFO: Resuming triggers.
[13:53:42.534] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:54:11.832] INFO: Resuming triggers.
[13:54:23.520] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:54:52.800] INFO: Resuming triggers.
[13:55:04.491] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:55:33.711] INFO: Resuming triggers.
[13:55:40.528] INFO: data taking finished, elapsed time: 100 seconds.
[13:55:57.873] INFO: PixTest:: pg_setup set to default.
[13:55:57.876] INFO: PixTestXray::doPhRun() done
[13:55:58.034] INFO: enter test to run
[13:56:46.040] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:56:46.040] INFO: running: xray
[13:56:46.041] INFO: ----------------------------------------------------------------------
[13:56:46.041] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:56:46.041] INFO: ----------------------------------------------------------------------
[13:56:47.006] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:56:53.851] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:56:53.916] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (201) != TBM ID (202)
[13:56:53.916] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[13:56:53.916] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (201) != TBM ID (202)
[13:56:53.916] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[13:56:53.916] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (203) != TBM ID (202)
[13:56:53.916] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (203) != TBM ID (202)
[13:56:53.916] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cd 80c0 43c8 43c8 5b 204d 43c8 43c8 242 244a 43c8 8b 284e 2d9 2081 43c8 85 244f 149 2249 549 2842 549 2a4e 80b 204f 43c8 43c8 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c7 8040 4388 4388 4388 4388 1d 2064 400 2668 754 244e 4388 cd 204f 254 2868 4388 4388 15 2849 759 2a4d 4388 59 2642 c5 2642 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c8 80b1 4388 313 2a80 4388 4388 458 2245 4388 212 2465 295 202e 28b 2049 4d0 204c 689 2043 4388 15 284a 15 244f d1 2085 248 22a1 4388 d8 244f 4388 4388 249 2649 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ca 80bc ff8 27f8 43c8 43c8 54a 204f 618 2462 751 2668 43c8 35c 224f 75d 2067 754 246a 849 266d 43c8 43c8 319 204f 30b 2a6b 43c8 310 2668 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ca 8000 43c8 43c8 43c8 298 2648 43c8 90 2047 353 2a4d 549 204f 43c8 43c8 809 2669 43c8 89 204a 350 242f 714 2a45 43c8 35b 2265 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cb 8040 43c8 541 2a2d 43c8 43c8 43c8 c9 206e 10a 2a63 154 2062 2c1 2444 6d3 2a4f 43c8 251 264d 251 2a6f 6c5 2283 43c8 5 286d 5 244a 12 2a67 24a 2285 749 246e 43c8 448 2462 43c8 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cc 80b1 43c8 15 246a 95 242e 43c8 43c8 450 2826 610 2044 43c8 43c8 43c8 14d 2061 43c8 a2 284d 219 2665 43c8 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cd 80c0 43c8 43c8 353 2a4d 849 284e 43c8 151 244a 43c8 43c8 249 204a 821 2049 43c8 13 244f 43c8 55c 262f 43c9 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c7 8040 4388 4388 85b 2a61 4388 d3 2249 2db 246a 4388 94 2241 4388 4388 251 286f 4388 820 244f 4388 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c8 80b1 4388 1b 2a49 343 2665 801 2a42 4388 705 2a2d 4388 4388 100 2840 4388 41b 2045 4388 313 2661 4388 4388 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ca 80b8 70 2a22 2a20 692 43c8 43c8 6d3 2288 43c8 43c8 358 2849 43c8 43c8 59 242d e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ca 8000 43c8 110 2442 612 2a4e 6c8 2a28 43c8 43c8 20 2065 11b 2663 43c8 43c8 43c8 2ca 2049 43c8 43c8 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cb 8040 43c8 c8 244f 859 2448 43c8 43c8 43c8 43c8 14b 2885 843 242f 43c8 43c8 43ca 4d 2441 e000 c000
[13:56:53.916] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cc 80b1 43c8 43c8 710 222b 43c8 69b 244a 69a 246e 43c8 1 202d 810 206d 43c8 43c8 20c 2045 43c8 861 2a61 43c9 e000 c000
[13:57:23.952] INFO: Resuming triggers.
[13:57:30.797] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:58:01.028] INFO: Resuming triggers.
[13:58:07.874] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:58:38.075] INFO: Resuming triggers.
[13:58:44.917] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:59:14.911] INFO: Resuming triggers.
[13:59:21.756] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:59:51.872] INFO: Resuming triggers.
[13:59:58.718] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:00:28.849] INFO: Resuming triggers.
[14:00:35.692] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:01:05.841] INFO: Resuming triggers.
[14:01:12.685] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:01:42.779] INFO: Resuming triggers.
[14:01:49.625] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:02:19.717] INFO: Resuming triggers.
[14:02:26.566] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:02:56.592] INFO: Resuming triggers.
[14:03:03.440] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:03:33.585] INFO: Resuming triggers.
[14:03:40.434] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:04:10.453] INFO: Resuming triggers.
[14:04:17.300] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:04:17.368] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[14:04:17.368] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 has NoTokenPass but 8 ROCs were found
[14:04:17.369] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a065 80c0 43c8 43c8 254 2047 2d2 2445 2d2 2082 31c 2648 858 264f 43c8 415 2a4b 43c8 445 2a6f 43c8 15 2a45 85 264f 10a 206b 44c 2681 450 224d 43c8 60d 208f 70a 2664 43c8 414 264c 813 2647 43c8 8 2a2f 9c 222d e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a05f 8040 438a 438a 6d4 2441 438a 438a 422 2069 44b 224d 55a 2a46 438a 15b 224f 290 2680 294 224d 438a 88 2841 438a 438a 55a 2a4d e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a060 80b1 4388 4388 4388 44b 2044 44c 2245 4388 201 2263 611 2464 4388 c5 264f 320 2081 4dd 224a 4388 699 202c 6e1 2449 748 226a 4388 2c2 2a2c 55b 224f 75b 2081 80d 264e 4388 1c 202d 12 284d 11 2662 c9 224a 215 2245 64b 266e e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a061 80c0 4388 4388 813 286d 4388 4388 3 246d 4389 4389 5b 2484 4389 2d9 2645 40a 2083 4389 5b 224d e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a062 8000 4388 4388 4389 68c 2a64 4389 4388 243 226d 243 2668 299 2462 304 266d 35a 264e 1461 206a aaf 2fef ea4 22a1 8aa 43c9 2e2 2262 43c9 9b 2264 e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a063 8040 43c8 20a 2665 515 2849 685 2a4e 43c9 19 224f 43c8 85a 2245 43c9 44b 246a 43c8 43c9 308 2845 300 2460 85d 2a80 43c8 dd 2483 43c9 458 282f e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a064 80b1 43c8 92 2441 43c8 11c 2440 43c8 43c8 43c8 43c8 d8 244c 312 2249 312 2681 440 244f 64d 224d 762 2a6d 43c8 6c1 2a27 43c8 c9 206a 115 244b e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a165 80c0 43c8 112 2866 145 2a83 43c8 43c8 43c8 1 2249 43c8 360 284f 43c8 2d4 2484 43c8 43c8 e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15f 8040 438a 438a 613 264c 438a 438a 660 2240 81a 224c 438a 438a 52 224d 461 244d 438a 4389 e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a160 80b1 4389 4389 4389 10 2449 4389 4389 621 2485 4389 4389 4388 30c 2685 e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a161 80c0 4388 6cc 262d 4388 360 204f 851 2649 4388 408 202f 4388 15 284f 861 2a68 4389 4389 4b 2466 2c5 2265 4389 4388 4d9 2243 e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a162 8000 4388 453 2864 4388 4389 245 2249 4389 4388 4388 1d 2461 4389 304 2a4c 649 2a4f 53c8 7fd 43cb 3f 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
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a163 8040 43c8 6c1 2642 43c9 110 222f 651 2649 71b 2045 43c8 43c9 1d 284f 710 204a 43c8 851 2244 43c9 112 2045 359 286f 43c8 43c8 6dd 260d e000 c000
[14:04:17.369] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a164 80b1 43c8 2a1 2480 43c8 295 2681 852 202d 851 2863 43c8 4a 2a49 43c8 660 264f 43c8 93 2a4a 43c8 43c8 759 2449 43c8 e000 c000
[14:04:47.362] INFO: Resuming triggers.
[14:04:54.212] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:05:24.287] INFO: Resuming triggers.
[14:05:28.753] INFO: data taking finished, elapsed time: 100 seconds.
[14:05:48.613] INFO: PixTest:: pg_setup set to default.
[14:05:48.616] INFO: PixTestXray::doPhRun() done
[14:05:48.763] INFO: enter test to run
[14:06:01.508] INFO: test: timing no parameter change
[14:06:01.508] INFO: running: timing
[14:06:01.511] INFO: ######################################################################
[14:06:01.511] INFO: PixTestTiming::doTest()
[14:06:01.511] INFO: ######################################################################
[14:06:01.512] INFO: ----------------------------------------------------------------------
[14:06:01.512] INFO: PixTestTiming::TBMPhaseScan()
[14:06:01.512] INFO: ----------------------------------------------------------------------
[14:10:59.111] INFO: TBM Phase Settings: 16
[14:10:59.111] INFO: 400MHz Phase: 4
[14:10:59.111] INFO: 160MHz Phase: 0
[14:10:59.111] INFO: Functional Phase Area: 2
[14:10:59.114] INFO: Test took 297603 ms.
[14:10:59.114] INFO: PixTestTiming::TBMPhaseScan() done.
[14:10:59.115] INFO: ----------------------------------------------------------------------
[14:10:59.115] INFO: PixTestTiming::ROCDelayScan()
[14:10:59.115] INFO: ----------------------------------------------------------------------
[14:14:09.446] INFO: ROC Delay Settings: 228
[14:14:09.446] INFO: ROC Header-Trailer/Token Delay: 11
[14:14:09.446] INFO: ROC Port 0 Delay: 4
[14:14:09.446] INFO: ROC Port 1 Delay: 4
[14:14:09.446] INFO: Functional ROC Area: 5
[14:14:09.449] INFO: Test took 190335 ms.
[14:14:09.449] INFO: PixTestTiming::ROCDelayScan() done.
[14:14:09.449] INFO: ----------------------------------------------------------------------
[14:14:09.449] INFO: PixTestTiming::TimingTest()
[14:14:09.449] INFO: ----------------------------------------------------------------------
[14:14:25.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:40.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:55.418] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:10.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:25.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:40.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:55.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:10.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:25.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:39.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:40.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:40.369] INFO: ----------------------------------------------------------------------
[14:16:40.369] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:16:40.369] INFO: ----------------------------------------------------------------------
[14:16:40.369] INFO: ----------------------------------------------------------------------
[14:16:40.369] INFO: Read back bit status: 1
[14:16:40.369] INFO: ----------------------------------------------------------------------
[14:16:40.369] INFO: ----------------------------------------------------------------------
[14:16:40.369] INFO: Timings are good!
[14:16:40.369] INFO: ----------------------------------------------------------------------
[14:16:40.369] INFO: Test took 150920 ms.
[14:16:40.369] INFO: PixTestTiming::TimingTest() done.
[14:16:40.369] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:16:40.369] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-47_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:16:40.369] INFO: PixTestTiming::doTest took 638861 ms.
[14:16:40.369] INFO: PixTestTiming::doTest() done
[14:16:40.369] INFO: Write out TBMPhaseScan_0_V0
[14:16:40.370] INFO: Write out TBMPhaseScan_1_V0
[14:16:40.370] INFO: Write out CombinedTBMPhaseScan_V0
[14:16:40.371] INFO: Write out ROCDelayScan3_V0
[14:16:40.371] INFO: enter test to run
[14:17:04.399] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:17:04.399] INFO: running: xray
[14:17:04.400] INFO: ----------------------------------------------------------------------
[14:17:04.400] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:17:04.400] INFO: ----------------------------------------------------------------------
[14:17:05.366] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:17:12.223] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:17:42.320] INFO: Resuming triggers.
[14:17:49.174] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:18:19.250] INFO: Resuming triggers.
[14:18:26.103] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:18:56.173] INFO: Resuming triggers.
[14:19:03.025] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:19:33.079] INFO: Resuming triggers.
[14:19:39.932] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:20:09.968] INFO: Resuming triggers.
[14:20:16.822] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:20:46.840] INFO: Resuming triggers.
[14:20:53.695] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:21:23.836] INFO: Resuming triggers.
[14:21:30.690] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:22:00.676] INFO: Resuming triggers.
[14:22:07.530] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:22:37.675] INFO: Resuming triggers.
[14:22:44.531] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:23:14.748] INFO: Resuming triggers.
[14:23:21.606] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:23:51.665] INFO: Resuming triggers.
[14:23:58.521] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:24:28.567] INFO: Resuming triggers.
[14:24:35.424] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:25:05.528] INFO: Resuming triggers.
[14:25:12.383] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:25:42.401] INFO: Resuming triggers.
[14:25:46.744] INFO: data taking finished, elapsed time: 100 seconds.
[14:26:06.027] INFO: PixTest:: pg_setup set to default.
[14:26:06.030] INFO: PixTestXray::doPhRun() done
[14:26:06.179] INFO: enter test to run
[14:26:33.707] INFO: test: HighRate no parameter change
[14:26:33.707] INFO: running: highrate
[14:26:33.708] INFO: ----------------------------------------------------------------------
[14:26:33.708] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:26:33.708] INFO: ----------------------------------------------------------------------
[14:26:33.851] INFO: Expecting 768 events.
[14:26:34.984] INFO: 768 events read in total (418ms).
[14:26:34.985] INFO: Test took 1269ms.
[14:26:35.787] INFO: Expecting 41600 events.
[14:26:38.820] INFO: 41600 events read in total (2506ms).
[14:26:38.821] INFO: Test took 3829ms.
[14:26:38.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:39.582] INFO: Expecting 41600 events.
[14:26:42.749] INFO: 41600 events read in total (2640ms).
[14:26:42.750] INFO: Test took 3882ms.
[14:26:42.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:43.512] INFO: Expecting 41600 events.
[14:26:46.708] INFO: 41600 events read in total (2670ms).
[14:26:46.708] INFO: Test took 3909ms.
[14:26:46.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:47.468] INFO: Expecting 41600 events.
[14:26:50.683] INFO: 41600 events read in total (2689ms).
[14:26:50.684] INFO: Test took 3926ms.
[14:26:50.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:51.446] INFO: Expecting 41600 events.
[14:26:54.676] INFO: 41600 events read in total (2703ms).
[14:26:54.677] INFO: Test took 3945ms.
[14:26:54.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:55.435] INFO: Expecting 41600 events.
[14:26:58.661] INFO: 41600 events read in total (2699ms).
[14:26:58.661] INFO: Test took 3933ms.
[14:26:58.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:59.420] INFO: Expecting 41600 events.
[14:27:02.645] INFO: 41600 events read in total (2698ms).
[14:27:02.646] INFO: Test took 3936ms.
[14:27:02.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:03.405] INFO: Expecting 41600 events.
[14:27:06.642] INFO: 41600 events read in total (2710ms).
[14:27:06.643] INFO: Test took 3948ms.
[14:27:06.675] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:07.404] INFO: Expecting 41600 events.
[14:27:10.626] INFO: 41600 events read in total (2695ms).
[14:27:10.627] INFO: Test took 3934ms.
[14:27:10.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:11.387] INFO: Expecting 41600 events.
[14:27:14.608] INFO: 41600 events read in total (2694ms).
[14:27:14.609] INFO: Test took 3933ms.
[14:27:14.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:15.366] INFO: Expecting 41600 events.
[14:27:18.615] INFO: 41600 events read in total (2722ms).
[14:27:18.616] INFO: Test took 3956ms.
[14:27:18.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:19.374] INFO: Expecting 41600 events.
[14:27:22.612] INFO: 41600 events read in total (2711ms).
[14:27:22.613] INFO: Test took 3948ms.
[14:27:22.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:23.372] INFO: Expecting 41600 events.
[14:27:26.609] INFO: 41600 events read in total (2710ms).
[14:27:26.610] INFO: Test took 3946ms.
[14:27:26.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:27.365] INFO: Expecting 41600 events.
[14:27:30.582] INFO: 41600 events read in total (2690ms).
[14:27:30.583] INFO: Test took 3923ms.
[14:27:30.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:31.343] INFO: Expecting 41600 events.
[14:27:34.567] INFO: 41600 events read in total (2697ms).
[14:27:34.567] INFO: Test took 3934ms.
[14:27:34.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:35.328] INFO: Expecting 41600 events.
[14:27:38.548] INFO: 41600 events read in total (2693ms).
[14:27:38.549] INFO: Test took 3931ms.
[14:27:38.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:39.306] INFO: Expecting 41600 events.
[14:27:42.533] INFO: 41600 events read in total (2700ms).
[14:27:42.534] INFO: Test took 3936ms.
[14:27:42.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:43.294] INFO: Expecting 41600 events.
[14:27:46.516] INFO: 41600 events read in total (2695ms).
[14:27:46.517] INFO: Test took 3934ms.
[14:27:46.549] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:47.276] INFO: Expecting 41600 events.
[14:27:50.491] INFO: 41600 events read in total (2688ms).
[14:27:50.492] INFO: Test took 3925ms.
[14:27:50.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:51.254] INFO: Expecting 41600 events.
[14:27:54.387] INFO: 41600 events read in total (2606ms).
[14:27:54.388] INFO: Test took 3846ms.
[14:27:54.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:54.785] INFO: enter test to run
[14:27:58.290] INFO: test: HighRate no parameter change
[14:27:58.291] INFO: running: highrate
[14:27:58.292] INFO: ----------------------------------------------------------------------
[14:27:58.292] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:27:58.292] INFO: ----------------------------------------------------------------------
[14:27:58.901] INFO: Expecting 208000 events.
[14:28:10.622] INFO: 208000 events read in total (11194ms).
[14:28:10.625] INFO: Test took 12325ms.
[14:28:10.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:11.008] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:28:11.009] INFO: number of red-efficiency pixels: 54 37 80 113 170 123 162 101 81 94 91 64 69 65 18 30
[14:28:11.009] INFO: number of X-ray hits detected: 57044 39801 64206 101864 106518 112023 114658 80915 72780 89856 83655 71404 74269 44718 21364 24696
[14:28:11.009] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:28:11.009] INFO: number of Vcal hits detected: 207946 207963 207914 207886 207828 207875 207831 207893 207917 207905 207909 207935 207929 207934 207981 207970
[14:28:11.009] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:28:11.009] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:28:11.009] INFO: X-ray hit rate [MHz/cm2]: 16.7 11.7 18.8 29.9 31.2 32.8 33.6 23.7 21.3 26.3 24.5 20.9 21.8 13.1 6.3 7.2
[14:28:11.009] INFO: PixTestHighRate::doXPixelAlive() done
[14:28:11.056] INFO: PixTest:: pg_setup set to default.
[14:28:11.072] INFO: enter test to run
[14:28:27.514] INFO: test: HighRate no parameter change
[14:28:27.514] INFO: running: highrate
[14:28:27.515] INFO: ----------------------------------------------------------------------
[14:28:27.515] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:28:27.515] INFO: ----------------------------------------------------------------------
[14:28:28.130] INFO: Expecting 208000 events.
[14:28:41.581] INFO: 208000 events read in total (12924ms).
[14:28:41.586] INFO: Test took 14061ms.
[14:28:41.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:42.163] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:28:42.163] INFO: number of red-efficiency pixels: 162 113 205 378 528 479 610 274 217 273 286 190 215 138 44 50
[14:28:42.163] INFO: number of X-ray hits detected: 122465 85208 136681 218696 226015 238750 244887 172724 156126 193813 178791 153295 157777 96886 45473 53600
[14:28:42.163] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:28:42.163] INFO: number of Vcal hits detected: 207829 207885 207782 207587 207432 207482 207329 207703 207773 207717 207702 207802 207777 207860 207956 207950
[14:28:42.163] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:28:42.163] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:28:42.164] INFO: X-ray hit rate [MHz/cm2]: 35.9 25.0 40.1 64.1 66.2 70.0 71.8 50.6 45.8 56.8 52.4 44.9 46.2 28.4 13.3 15.7
[14:28:42.164] INFO: PixTestHighRate::doXPixelAlive() done
[14:28:42.214] INFO: PixTest:: pg_setup set to default.
[14:28:42.228] INFO: enter test to run
[14:29:00.890] INFO: test: HighRate no parameter change
[14:29:00.890] INFO: running: highrate
[14:29:00.891] INFO: ----------------------------------------------------------------------
[14:29:00.891] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:29:00.891] INFO: ----------------------------------------------------------------------
[14:29:01.511] INFO: Expecting 208000 events.
[14:29:16.876] INFO: 208000 events read in total (14838ms).
[14:29:16.883] INFO: Test took 15983ms.
[14:29:17.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:17.660] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:29:17.660] INFO: number of red-efficiency pixels: 338 262 444 878 1182 1110 1345 644 408 631 698 446 511 320 81 94
[14:29:17.660] INFO: number of X-ray hits detected: 185342 129308 209194 331117 344460 365033 372034 264041 238672 294253 270463 232323 242275 146918 69537 81188
[14:29:17.660] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:29:17.660] INFO: number of Vcal hits detected: 207635 207712 207476 206953 206493 206610 206230 207232 207553 207302 207206 207522 207440 207641 207919 207902
[14:29:17.660] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.5 99.4 99.4 99.2 99.7 99.8 99.7 99.6 99.8 99.8 99.8 100.0 100.0
[14:29:17.660] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.3 99.3 99.1 99.6 99.8 99.7 99.6 99.8 99.7 99.8 100.0 100.0
[14:29:17.660] INFO: X-ray hit rate [MHz/cm2]: 54.3 37.9 61.3 97.1 101.0 107.0 109.0 77.4 70.0 86.2 79.3 68.1 71.0 43.1 20.4 23.8
[14:29:17.660] INFO: PixTestHighRate::doXPixelAlive() done
[14:29:17.711] INFO: PixTest:: pg_setup set to default.
[14:29:17.725] INFO: enter test to run
[14:29:24.474] INFO: test: exit no parameter change
[14:29:24.852] QUIET: Connection to board 33 closed.
[14:29:24.854] INFO: pXar: this is the end, my friend