[14:36:09.160] INFO: *** Welcome to pxar ***
[14:36:09.160] INFO: *** Today: 2016/05/25
[14:36:09.218] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:36:09.218] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//dacParameters35_C15.dat
[14:36:09.232] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:36:09.232] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//defaultMaskFile.dat
[14:36:09.237] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C15.dat
[14:36:09.332] INFO: clk: 4
[14:36:09.332] INFO: ctr: 4
[14:36:09.332] INFO: sda: 19
[14:36:09.332] INFO: tin: 9
[14:36:09.332] INFO: level: 15
[14:36:09.332] INFO: triggerdelay: 0
[14:36:09.332] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:36:09.332] INFO: Log level: INFO
[14:36:09.349] QUIET: Connection to board DTB_WREKRL opened.
[14:36:09.353] 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:
------------------------------------------------------
[14:36:09.356] INFO: RPC call hashes of host and DTB match: 398089610
[14:36:10.893] INFO: DUT info:
[14:36:10.893] INFO: The DUT currently contains the following objects:
[14:36:10.893] INFO: 2 TBM Cores tbm08c (2 ON)
[14:36:10.893] INFO: TBM Core alpha (0): 7 registers set
[14:36:10.893] INFO: TBM Core beta (1): 7 registers set
[14:36:10.893] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:36:10.894] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:10.894] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:11.298] INFO: enter 'restricted' command line mode
[14:36:11.298] INFO: enter test to run
[14:36:20.002] INFO: test: PixelAlive no parameter change
[14:36:20.002] INFO: running: pixelalive
[14:36:21.008] INFO: ----------------------------------------------------------------------
[14:36:21.008] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:36:21.008] INFO: ----------------------------------------------------------------------
[14:36:21.323] INFO: Expecting 41600 events.
[14:36:25.658] INFO: 41600 events read in total (3616ms).
[14:36:25.827] INFO: Test took 4816ms.
[14:36:25.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:26.100] INFO: PixTestAlive::aliveTest() done
[14:36:26.101] INFO: number of dead pixels (per ROC): 0 0 0 160 0 0 0 0 0 0 1 0 0 0 0 0
[14:36:26.134] INFO: enter test to run
[14:36:42.313] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:36:42.313] INFO: running: highrate
[14:36:42.314] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:36:42.525] INFO: ----------------------------------------------------------------------
[14:36:42.525] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:36:42.525] INFO: ----------------------------------------------------------------------
[14:36:42.525] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:36:42.525] INFO: edge/corner pixel THR is adjusted
[14:36:42.525] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:36:43.484] INFO: Collecting data for 5 seconds...
[14:36:48.501] INFO: Done with hot pixel readout
[14:37:00.854] INFO: PixTest:: pg_setup set to default.

[14:37:00.855] INFO: 88 hot pixels found in step 0
[14:37:01.852] INFO: Collecting data for 5 seconds...
[14:37:06.868] INFO: Done with hot pixel readout
[14:37:19.200] INFO: PixTest:: pg_setup set to default.



[14:37:19.201] INFO: 82 hot pixels found in step 1
[14:37:20.195] INFO: Collecting data for 5 seconds...
[14:37:25.211] INFO: Done with hot pixel readout
[14:37:37.473] INFO: PixTest:: pg_setup set to default.




[14:37:37.474] INFO: 91 hot pixels found in step 2
[14:37:38.472] INFO: Collecting data for 5 seconds...
[14:37:43.489] INFO: Done with hot pixel readout
[14:37:55.520] INFO: PixTest:: pg_setup set to default.



[14:37:55.521] INFO: 62 hot pixels found in step 3
[14:37:56.520] INFO: Collecting data for 5 seconds...
[14:38:01.536] INFO: Done with hot pixel readout
[14:38:13.682] INFO: PixTest:: pg_setup set to default.







[14:38:13.683] INFO: 78 hot pixels found in step 4
[14:38:14.680] INFO: Collecting data for 5 seconds...
[14:38:19.696] INFO: Done with hot pixel readout
[14:38:32.076] INFO: PixTest:: pg_setup set to default.






[14:38:32.077] INFO: 71 hot pixels found in step 5
[14:38:33.076] INFO: Collecting data for 5 seconds...
[14:38:38.092] INFO: Done with hot pixel readout
[14:38:50.523] INFO: PixTest:: pg_setup set to default.









[14:38:50.524] INFO: 67 hot pixels found in step 6
[14:38:51.523] INFO: Collecting data for 5 seconds...
[14:38:56.538] INFO: Done with hot pixel readout
[14:39:08.858] INFO: PixTest:: pg_setup set to default.











[14:39:08.859] INFO: 76 hot pixels found in step 7
[14:39:09.859] INFO: Collecting data for 5 seconds...
[14:39:14.876] INFO: Done with hot pixel readout
[14:39:26.926] INFO: PixTest:: pg_setup set to default.









[14:39:26.928] INFO: 64 hot pixels found in step 8
[14:39:27.926] INFO: Collecting data for 5 seconds...
[14:39:32.943] INFO: Done with hot pixel readout
[14:39:44.928] INFO: PixTest:: pg_setup set to default.










[14:39:44.929] INFO: 55 hot pixels found in step 9
[14:39:45.928] INFO: Collecting data for 5 seconds...
[14:39:50.944] INFO: Done with hot pixel readout
[14:40:03.334] INFO: PixTest:: pg_setup set to default.















[14:40:03.335] INFO: 73 hot pixels found in step 10
[14:40:04.343] INFO: Collecting data for 5 seconds...
[14:40:09.360] INFO: Done with hot pixel readout
[14:40:21.557] INFO: PixTest:: pg_setup set to default.












[14:40:21.558] INFO: 49 hot pixels found in step 11
[14:40:22.559] INFO: Collecting data for 5 seconds...
[14:40:27.577] INFO: Done with hot pixel readout
[14:40:39.390] INFO: PixTest:: pg_setup set to default.
















[14:40:39.391] INFO: 65 hot pixels found in step 12
[14:40:40.390] INFO: Collecting data for 5 seconds...
[14:40:45.408] INFO: Done with hot pixel readout
[14:40:57.640] INFO: PixTest:: pg_setup set to default.













[14:40:57.641] INFO: 43 hot pixels found in step 13
[14:40:58.639] INFO: Collecting data for 5 seconds...
[14:41:03.657] INFO: Done with hot pixel readout
[14:41:16.059] INFO: PixTest:: pg_setup set to default.










[14:41:16.061] INFO: 46 hot pixels found in step 14
[14:41:16.104] INFO: 46 hot pixels could not be trimmed and have been masked.
[14:41:16.108] INFO: PixTest::trimHotPixels() done
[14:41:16.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C0.dat
[14:41:16.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C1.dat
[14:41:16.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C2.dat
[14:41:16.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C3.dat
[14:41:16.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C4.dat
[14:41:16.155] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C5.dat
[14:41:16.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C6.dat
[14:41:16.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C7.dat
[14:41:16.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C8.dat
[14:41:16.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C9.dat
[14:41:16.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C10.dat
[14:41:16.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C11.dat
[14:41:16.202] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C12.dat
[14:41:16.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C13.dat
[14:41:16.213] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C14.dat
[14:41:16.219] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C15.dat
[14:41:16.224] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//defaultMaskFile.dat
[14:41:16.234] INFO: enter test to run
[14:41:34.271] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:41:34.272] INFO: running: highrate
[14:41:34.276] INFO: ----------------------------------------------------------------------
[14:41:34.276] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:41:34.276] INFO: ----------------------------------------------------------------------
[14:41:34.276] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:41:34.276] INFO: edge/corner pixel THR is adjusted
[14:41:34.276] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:41:35.233] INFO: Collecting data for 1 seconds...
[14:41:36.237] INFO: Done with hot pixel readout
[14:41:40.764] INFO: PixTest:: pg_setup set to default.
[14:41:40.765] INFO: 0 hot pixels found in step 0
[14:41:40.774] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:41:40.795] INFO: PixTest::trimHotPixels() done
[14:41:40.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C0.dat
[14:41:40.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C1.dat
[14:41:40.816] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C2.dat
[14:41:40.826] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C3.dat
[14:41:40.835] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C4.dat
[14:41:40.843] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C5.dat
[14:41:40.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C6.dat
[14:41:40.862] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C7.dat
[14:41:40.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C8.dat
[14:41:40.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C9.dat
[14:41:40.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C10.dat
[14:41:40.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C11.dat
[14:41:40.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C12.dat
[14:41:40.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C13.dat
[14:41:40.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C14.dat
[14:41:40.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C15.dat
[14:41:40.926] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NV_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//defaultMaskFile.dat
[14:41:40.936] INFO: enter test to run
[14:42:28.663] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:42:28.663] INFO: running: xray
[14:42:28.664] INFO: ----------------------------------------------------------------------
[14:42:28.664] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:42:28.664] INFO: ----------------------------------------------------------------------
[14:42:29.628] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:42:40.355] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:43:10.836] INFO: Resuming triggers.
[14:43:21.564] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:43:51.282] INFO: Resuming triggers.
[14:44:01.004] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:44:31.492] INFO: Resuming triggers.
[14:44:42.218] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:45:11.836] INFO: Resuming triggers.
[14:45:22.563] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:45:52.086] INFO: Resuming triggers.
[14:46:02.818] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:46:32.351] INFO: Resuming triggers.
[14:46:43.077] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:47:12.678] INFO: Resuming triggers.
[14:47:23.405] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:47:53.041] INFO: Resuming triggers.
[14:48:03.765] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:48:33.413] INFO: Resuming triggers.
[14:48:37.222] INFO: data taking finished, elapsed time: 100 seconds.
[14:48:47.778] INFO: PixTest:: pg_setup set to default.
[14:48:47.781] INFO: PixTestXray::doPhRun() done
[14:48:47.920] INFO: enter test to run
[14:49:26.196] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:49:26.196] INFO: running: xray
[14:49:26.197] INFO: ----------------------------------------------------------------------
[14:49:26.197] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:49:26.197] INFO: ----------------------------------------------------------------------
[14:49:27.170] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:49:33.104] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[14:50:03.414] INFO: Resuming triggers.
[14:50:09.342] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:50:39.535] INFO: Resuming triggers.
[14:50:45.461] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[14:51:15.704] INFO: Resuming triggers.
[14:51:21.639] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:51:52.181] INFO: Resuming triggers.
[14:51:58.109] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[14:52:28.715] INFO: Resuming triggers.
[14:52:34.651] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:53:05.709] INFO: Resuming triggers.
[14:53:11.639] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:53:42.711] INFO: Resuming triggers.
[14:53:48.642] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:54:20.461] INFO: Resuming triggers.
[14:54:26.390] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:54:56.606] INFO: Resuming triggers.
[14:55:02.544] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:55:32.762] INFO: Resuming triggers.
[14:55:38.691] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:56:08.918] INFO: Resuming triggers.
[14:56:14.848] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:56:45.013] INFO: Resuming triggers.
[14:56:50.948] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:57:21.145] INFO: Resuming triggers.
[14:57:27.080] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:57:57.315] INFO: Resuming triggers.
[14:58:03.251] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:58:33.351] INFO: Resuming triggers.
[14:58:39.279] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:59:09.482] INFO: Resuming triggers.
[14:59:14.922] INFO: data taking finished, elapsed time: 100 seconds.
[14:59:42.798] INFO: PixTest:: pg_setup set to default.
[14:59:42.801] INFO: PixTestXray::doPhRun() done
[14:59:42.950] INFO: enter test to run
[15:00:32.567] INFO: test: HighRate no parameter change
[15:00:32.567] INFO: running: highrate
[15:00:32.568] INFO: ----------------------------------------------------------------------
[15:00:32.568] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:00:32.568] INFO: ----------------------------------------------------------------------
[15:00:32.709] INFO: Expecting 768 events.
[15:00:33.843] INFO: 768 events read in total (418ms).
[15:00:33.844] INFO: Test took 1268ms.
[15:00:34.647] INFO: Expecting 41600 events.
[15:00:37.611] INFO: 41600 events read in total (2437ms).
[15:00:37.612] INFO: Test took 3759ms.
[15:00:37.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:38.372] INFO: Expecting 41600 events.
[15:00:41.633] INFO: 41600 events read in total (2734ms).
[15:00:41.634] INFO: Test took 3964ms.
[15:00:41.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:42.389] INFO: Expecting 41600 events.
[15:00:45.675] INFO: 41600 events read in total (2759ms).
[15:00:45.676] INFO: Test took 3985ms.
[15:00:45.715] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:46.427] INFO: Expecting 41600 events.
[15:00:49.707] INFO: 41600 events read in total (2754ms).
[15:00:49.708] INFO: Test took 3975ms.
[15:00:49.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:50.459] INFO: Expecting 41600 events.
[15:00:53.740] INFO: 41600 events read in total (2754ms).
[15:00:53.742] INFO: Test took 3973ms.
[15:00:53.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:54.496] INFO: Expecting 41600 events.
[15:00:57.797] INFO: 41600 events read in total (2774ms).
[15:00:57.798] INFO: Test took 3997ms.
[15:00:57.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:58.552] INFO: Expecting 41600 events.
[15:01:01.839] INFO: 41600 events read in total (2760ms).
[15:01:01.840] INFO: Test took 3982ms.
[15:01:01.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:02.591] INFO: Expecting 41600 events.
[15:01:05.885] INFO: 41600 events read in total (2767ms).
[15:01:05.886] INFO: Test took 3986ms.
[15:01:05.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:06.639] INFO: Expecting 41600 events.
[15:01:09.931] INFO: 41600 events read in total (2765ms).
[15:01:09.932] INFO: Test took 3987ms.
[15:01:09.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:10.687] INFO: Expecting 41600 events.
[15:01:13.988] INFO: 41600 events read in total (2774ms).
[15:01:13.989] INFO: Test took 3998ms.
[15:01:14.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:14.744] INFO: Expecting 41600 events.
[15:01:18.040] INFO: 41600 events read in total (2769ms).
[15:01:18.041] INFO: Test took 3992ms.
[15:01:18.081] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:18.793] INFO: Expecting 41600 events.
[15:01:22.084] INFO: 41600 events read in total (2765ms).
[15:01:22.086] INFO: Test took 3986ms.
[15:01:22.125] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:22.839] INFO: Expecting 41600 events.
[15:01:26.152] INFO: 41600 events read in total (2786ms).
[15:01:26.153] INFO: Test took 4007ms.
[15:01:26.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:26.906] INFO: Expecting 41600 events.
[15:01:30.206] INFO: 41600 events read in total (2773ms).
[15:01:30.207] INFO: Test took 3995ms.
[15:01:30.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:30.956] INFO: Expecting 41600 events.
[15:01:34.240] INFO: 41600 events read in total (2757ms).
[15:01:34.241] INFO: Test took 3975ms.
[15:01:34.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:34.993] INFO: Expecting 41600 events.
[15:01:38.299] INFO: 41600 events read in total (2780ms).
[15:01:38.300] INFO: Test took 4000ms.
[15:01:38.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:39.054] INFO: Expecting 41600 events.
[15:01:42.352] INFO: 41600 events read in total (2771ms).
[15:01:42.353] INFO: Test took 3994ms.
[15:01:42.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:43.106] INFO: Expecting 41600 events.
[15:01:46.398] INFO: 41600 events read in total (2765ms).
[15:01:46.399] INFO: Test took 3986ms.
[15:01:46.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:47.154] INFO: Expecting 41600 events.
[15:01:50.440] INFO: 41600 events read in total (2759ms).
[15:01:50.441] INFO: Test took 3982ms.
[15:01:50.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:51.194] INFO: Expecting 41600 events.
[15:01:54.387] INFO: 41600 events read in total (2666ms).
[15:01:54.389] INFO: Test took 3889ms.
[15:01:54.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:54.780] INFO: enter test to run
[15:02:18.838] INFO: test: HighRate no parameter change
[15:02:18.838] INFO: running: highrate
[15:02:18.839] INFO: ----------------------------------------------------------------------
[15:02:18.839] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:02:18.839] INFO: ----------------------------------------------------------------------
[15:02:19.449] INFO: Expecting 208000 events.
[15:02:31.597] INFO: 208000 events read in total (11621ms).
[15:02:31.601] INFO: Test took 12753ms.
[15:02:31.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:32.033] INFO: number of dead pixels (per ROC): 0 0 0 42 0 0 0 0 0 0 1 0 0 0 0 0
[15:02:32.033] INFO: number of red-efficiency pixels: 77 76 102 349 168 179 165 132 118 134 155 132 169 79 35 29
[15:02:32.033] INFO: number of X-ray hits detected: 75664 53155 83643 134772 136003 143315 141796 99823 89583 113997 112187 96548 104384 59206 26055 31243
[15:02:32.033] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:02:32.033] INFO: number of Vcal hits detected: 207922 207921 207897 201256 207825 207819 207832 207863 207879 207866 207791 207863 207827 207918 207965 207971
[15:02:32.033] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 97.7 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:02:32.033] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 96.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:02:32.033] INFO: X-ray hit rate [MHz/cm2]: 22.2 15.6 24.5 39.5 39.9 42.0 41.6 29.3 26.3 33.4 32.9 28.3 30.6 17.4 7.6 9.2
[15:02:32.033] INFO: PixTestHighRate::doXPixelAlive() done
[15:02:32.077] INFO: PixTest:: pg_setup set to default.
[15:02:32.092] INFO: enter test to run
[15:02:54.726] INFO: test: HighRate no parameter change
[15:02:54.726] INFO: running: highrate
[15:02:54.727] INFO: ----------------------------------------------------------------------
[15:02:54.727] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:02:54.727] INFO: ----------------------------------------------------------------------
[15:02:55.346] INFO: Expecting 208000 events.
[15:03:09.650] INFO: 208000 events read in total (13777ms).
[15:03:09.656] INFO: Test took 14920ms.
[15:03:10.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:10.341] INFO: number of dead pixels (per ROC): 0 0 0 77 0 0 0 0 0 0 1 0 0 0 0 0
[15:03:10.341] INFO: number of red-efficiency pixels: 209 174 330 888 535 585 627 359 341 439 515 389 505 181 64 89
[15:03:10.341] INFO: number of X-ray hits detected: 157168 109663 172024 274036 280766 296820 293836 206119 185520 235881 232700 201355 214660 122536 54447 65427
[15:03:10.341] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:03:10.341] INFO: number of Vcal hits detected: 207766 207820 207630 199388 207426 207356 207309 207608 207633 207534 207387 207580 207445 207807 207933 207910
[15:03:10.341] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 97.6 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:03:10.341] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 95.9 99.7 99.7 99.7 99.8 99.8 99.8 99.7 99.8 99.7 99.9 100.0 100.0
[15:03:10.341] INFO: X-ray hit rate [MHz/cm2]: 46.1 32.1 50.4 80.3 82.3 87.0 86.1 60.4 54.4 69.1 68.2 59.0 62.9 35.9 16.0 19.2
[15:03:10.341] INFO: PixTestHighRate::doXPixelAlive() done
[15:03:10.386] INFO: PixTest:: pg_setup set to default.
[15:03:10.406] INFO: enter test to run
[15:04:14.109] INFO: test: HighRate no parameter change
[15:04:14.109] INFO: running: highrate
[15:04:14.111] INFO: ----------------------------------------------------------------------
[15:04:14.111] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:04:14.111] INFO: ----------------------------------------------------------------------
[15:04:14.728] INFO: Expecting 208000 events.
[15:04:31.734] INFO: 208000 events read in total (16479ms).
[15:04:31.743] INFO: Test took 17624ms.
[15:04:32.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:32.681] INFO: number of dead pixels (per ROC): 0 0 0 31 0 0 0 0 0 0 1 0 0 0 0 0
[15:04:32.681] INFO: number of red-efficiency pixels: 484 415 728 1871 1271 1479 1428 846 811 944 1117 914 1095 429 111 125
[15:04:32.682] INFO: number of X-ray hits detected: 235910 165610 261530 415868 422592 447225 444089 313276 280153 356914 351771 302919 326395 186283 82383 98384
[15:04:32.682] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:04:32.682] INFO: number of Vcal hits detected: 207444 207542 207006 197833 206342 205974 206052 206868 207033 206884 206553 206867 206671 207501 207885 207871
[15:04:32.682] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 95.8 99.3 99.1 99.2 99.5 99.6 99.5 99.4 99.5 99.4 99.8 99.9 99.9
[15:04:32.682] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 95.1 99.2 99.0 99.1 99.5 99.5 99.5 99.3 99.5 99.4 99.8 99.9 99.9
[15:04:32.682] INFO: X-ray hit rate [MHz/cm2]: 69.1 48.5 76.7 121.9 123.9 131.1 130.2 91.8 82.1 104.6 103.1 88.8 95.7 54.6 24.1 28.8
[15:04:32.682] INFO: PixTestHighRate::doXPixelAlive() done
[15:04:32.730] INFO: PixTest:: pg_setup set to default.
[15:04:32.748] INFO: enter test to run
[15:04:36.629] INFO: test: exit no parameter change
[15:04:36.945] QUIET: Connection to board 33 closed.
[15:04:36.946] INFO: pXar: this is the end, my friend