[13:04:26.410] INFO: *** Welcome to pxar ***
[13:04:26.410] INFO: *** Today: 2016/05/06
[13:04:26.441] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:04:26.441] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//dacParameters35_C15.dat
[13:04:26.479] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:04:26.479] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//defaultMaskFile.dat
[13:04:26.480] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C15.dat
[13:04:26.613] INFO: clk: 4
[13:04:26.613] INFO: ctr: 4
[13:04:26.613] INFO: sda: 19
[13:04:26.613] INFO: tin: 9
[13:04:26.613] INFO: level: 15
[13:04:26.613] INFO: triggerdelay: 0
[13:04:26.613] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:04:26.613] INFO: Log level: INFO
[13:04:26.632] QUIET: Connection to board DTB_WREKRL opened.
[13:04:26.635] 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:04:26.638] INFO: RPC call hashes of host and DTB match: 398089610
[13:04:28.167] INFO: DUT info:
[13:04:28.167] INFO: The DUT currently contains the following objects:
[13:04:28.167] INFO: 2 TBM Cores tbm08c (2 ON)
[13:04:28.167] INFO: TBM Core alpha (0): 7 registers set
[13:04:28.167] INFO: TBM Core beta (1): 7 registers set
[13:04:28.167] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:04:28.167] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.167] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.168] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.168] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:04:28.580] INFO: enter 'restricted' command line mode
[13:04:28.580] INFO: enter test to run
[13:04:38.487] INFO: test: PixelAlive no parameter change
[13:04:38.487] INFO: running: pixelalive
[13:04:38.496] INFO: ----------------------------------------------------------------------
[13:04:38.496] 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:04:38.496] INFO: ----------------------------------------------------------------------
[13:04:38.816] INFO: Expecting 41600 events.
[13:04:43.139] INFO: 41600 events read in total (3605ms).
[13:04:43.305] INFO: Test took 4806ms.
[13:04:43.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:43.578] INFO: PixTestAlive::aliveTest() done
[13:04:43.578] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:04:43.608] INFO: enter test to run
[13:05:31.639] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:05:31.639] INFO: running: highrate
[13:05:31.639] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:05:31.850] INFO: ----------------------------------------------------------------------
[13:05:31.850] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:05:31.850] INFO: ----------------------------------------------------------------------
[13:05:31.850] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:05:31.850] INFO: edge/corner pixel THR is adjusted
[13:05:31.850] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:05:32.809] INFO: Collecting data for 5 seconds...
[13:05:37.824] INFO: Done with hot pixel readout
[13:05:50.149] INFO: PixTest:: pg_setup set to default.


[13:05:50.150] INFO: 56 hot pixels found in step 0
[13:05:51.143] INFO: Collecting data for 5 seconds...
[13:05:56.160] INFO: Done with hot pixel readout
[13:06:08.441] INFO: PixTest:: pg_setup set to default.

[13:06:08.442] INFO: 53 hot pixels found in step 1
[13:06:09.438] INFO: Collecting data for 5 seconds...
[13:06:14.455] INFO: Done with hot pixel readout
[13:06:26.722] INFO: PixTest:: pg_setup set to default.

[13:06:26.723] INFO: 50 hot pixels found in step 2
[13:06:27.719] INFO: Collecting data for 5 seconds...
[13:06:32.737] INFO: Done with hot pixel readout
[13:06:45.004] INFO: PixTest:: pg_setup set to default.

[13:06:45.005] INFO: 44 hot pixels found in step 3
[13:06:45.001] INFO: Collecting data for 5 seconds...
[13:06:51.018] INFO: Done with hot pixel readout
[13:07:03.293] INFO: PixTest:: pg_setup set to default.


[13:07:03.294] INFO: 54 hot pixels found in step 4
[13:07:04.290] INFO: Collecting data for 5 seconds...
[13:07:09.307] INFO: Done with hot pixel readout
[13:07:21.627] INFO: PixTest:: pg_setup set to default.

[13:07:21.628] INFO: 45 hot pixels found in step 5
[13:07:22.624] INFO: Collecting data for 5 seconds...
[13:07:27.642] INFO: Done with hot pixel readout
[13:07:39.620] INFO: PixTest:: pg_setup set to default.



[13:07:39.621] INFO: 48 hot pixels found in step 6
[13:07:40.618] INFO: Collecting data for 5 seconds...
[13:07:45.636] INFO: Done with hot pixel readout
[13:07:57.818] INFO: PixTest:: pg_setup set to default.




[13:07:57.819] INFO: 49 hot pixels found in step 7
[13:07:58.819] INFO: Collecting data for 5 seconds...
[13:08:03.839] INFO: Done with hot pixel readout
[13:08:16.035] INFO: PixTest:: pg_setup set to default.








[13:08:16.036] INFO: 45 hot pixels found in step 8
[13:08:17.032] INFO: Collecting data for 5 seconds...
[13:08:22.051] INFO: Done with hot pixel readout
[13:08:33.989] INFO: PixTest:: pg_setup set to default.






[13:08:33.990] INFO: 39 hot pixels found in step 9
[13:08:34.986] INFO: Collecting data for 5 seconds...
[13:08:40.003] INFO: Done with hot pixel readout
[13:08:52.304] INFO: PixTest:: pg_setup set to default.








[13:08:52.305] INFO: 34 hot pixels found in step 10
[13:08:53.302] INFO: Collecting data for 5 seconds...
[13:08:58.318] INFO: Done with hot pixel readout
[13:09:10.650] INFO: PixTest:: pg_setup set to default.






[13:09:10.651] INFO: 36 hot pixels found in step 11
[13:09:11.647] INFO: Collecting data for 5 seconds...
[13:09:16.663] INFO: Done with hot pixel readout
[13:09:28.995] INFO: PixTest:: pg_setup set to default.







[13:09:28.996] INFO: 32 hot pixels found in step 12
[13:09:29.992] INFO: Collecting data for 5 seconds...
[13:09:35.008] INFO: Done with hot pixel readout
[13:09:47.326] INFO: PixTest:: pg_setup set to default.










[13:09:47.327] INFO: 28 hot pixels found in step 13
[13:09:48.328] INFO: Collecting data for 5 seconds...
[13:09:53.345] INFO: Done with hot pixel readout
[13:10:05.613] INFO: PixTest:: pg_setup set to default.








[13:10:05.614] INFO: 34 hot pixels found in step 14
[13:10:05.654] INFO: 34 hot pixels could not be trimmed and have been masked.
[13:10:05.658] INFO: PixTest::trimHotPixels() done
[13:10:05.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C0.dat
[13:10:05.682] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C1.dat
[13:10:05.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C2.dat
[13:10:05.702] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C3.dat
[13:10:05.708] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C4.dat
[13:10:05.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C5.dat
[13:10:05.718] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C6.dat
[13:10:05.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C7.dat
[13:10:05.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C8.dat
[13:10:05.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C9.dat
[13:10:05.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C10.dat
[13:10:05.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C11.dat
[13:10:05.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C12.dat
[13:10:05.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C13.dat
[13:10:05.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C14.dat
[13:10:05.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C15.dat
[13:10:05.770] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//defaultMaskFile.dat
[13:10:05.787] INFO: enter test to run
[13:10:44.220] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:10:44.220] INFO: running: highrate
[13:10:44.225] INFO: ----------------------------------------------------------------------
[13:10:44.225] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:10:44.225] INFO: ----------------------------------------------------------------------
[13:10:44.225] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:10:44.225] INFO: edge/corner pixel THR is adjusted
[13:10:44.225] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:10:45.183] INFO: Collecting data for 1 seconds...
[13:10:46.187] INFO: Done with hot pixel readout
[13:10:50.127] INFO: PixTest:: pg_setup set to default.
[13:10:50.128] INFO: 0 hot pixels found in step 0
[13:10:50.133] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:10:50.227] INFO: PixTest::trimHotPixels() done
[13:10:50.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C0.dat
[13:10:50.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C1.dat
[13:10:50.241] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C2.dat
[13:10:50.246] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C3.dat
[13:10:50.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C4.dat
[13:10:50.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C5.dat
[13:10:50.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C6.dat
[13:10:50.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C7.dat
[13:10:50.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C8.dat
[13:10:50.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C9.dat
[13:10:50.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C10.dat
[13:10:50.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C11.dat
[13:10:50.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C12.dat
[13:10:50.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C13.dat
[13:10:50.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C14.dat
[13:10:50.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C15.dat
[13:10:50.315] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-2-41_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//defaultMaskFile.dat
[13:10:50.325] INFO: enter test to run
[13:11:06.020] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:11:06.020] INFO: running: xray
[13:11:06.045] INFO: ----------------------------------------------------------------------
[13:11:06.045] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:11:06.045] INFO: ----------------------------------------------------------------------
[13:11:07.008] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:11:18.203] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:11:47.713] INFO: Resuming triggers.
[13:11:58.913] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:12:28.961] INFO: Resuming triggers.
[13:12:40.159] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:13:09.001] INFO: Resuming triggers.
[13:13:21.201] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:13:51.012] INFO: Resuming triggers.
[13:14:02.210] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:14:31.737] INFO: Resuming triggers.
[13:14:42.934] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:15:12.421] INFO: Resuming triggers.
[13:15:23.619] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:15:53.057] INFO: Resuming triggers.
[13:16:04.253] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:16:33.792] INFO: Resuming triggers.
[13:16:44.557] INFO: data taking finished, elapsed time: 100 seconds.
[13:17:13.037] INFO: PixTest:: pg_setup set to default.
[13:17:13.040] INFO: PixTestXray::doPhRun() done
[13:17:13.178] INFO: enter test to run
[13:18:17.809] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:18:17.809] INFO: running: xray
[13:18:17.810] INFO: ----------------------------------------------------------------------
[13:18:17.810] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:18:17.810] INFO: ----------------------------------------------------------------------
[13:18:18.781] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:18:25.530] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:18:56.192] INFO: Resuming triggers.
[13:19:02.947] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:19:33.147] INFO: Resuming triggers.
[13:19:39.898] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:20:09.833] INFO: Resuming triggers.
[13:20:16.584] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:20:46.664] INFO: Resuming triggers.
[13:20:53.420] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:21:23.392] INFO: Resuming triggers.
[13:21:30.146] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:22:00.160] INFO: Resuming triggers.
[13:22:06.911] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:22:36.849] INFO: Resuming triggers.
[13:22:43.605] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:23:14.287] INFO: Resuming triggers.
[13:23:21.040] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:23:52.126] INFO: Resuming triggers.
[13:23:58.880] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:24:29.916] INFO: Resuming triggers.
[13:24:36.670] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:25:06.862] INFO: Resuming triggers.
[13:25:13.614] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:25:43.696] INFO: Resuming triggers.
[13:25:50.448] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:26:20.472] INFO: Resuming triggers.
[13:26:27.227] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:26:57.269] INFO: Resuming triggers.
[13:27:03.069] INFO: data taking finished, elapsed time: 100 seconds.
[13:27:29.118] INFO: PixTest:: pg_setup set to default.
[13:27:29.121] INFO: PixTestXray::doPhRun() done
[13:27:29.270] INFO: enter test to run
[13:28:08.317] INFO: test: HighRate no parameter change
[13:28:08.317] INFO: running: highrate
[13:28:08.318] INFO: ----------------------------------------------------------------------
[13:28:08.318] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:28:08.318] INFO: ----------------------------------------------------------------------
[13:28:08.458] INFO: Expecting 768 events.
[13:28:09.606] INFO: 768 events read in total (433ms).
[13:28:09.612] INFO: Test took 1288ms.
[13:28:10.409] INFO: Expecting 41600 events.
[13:28:13.462] INFO: 41600 events read in total (2526ms).
[13:28:13.463] INFO: Test took 3842ms.
[13:28:13.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:14.224] INFO: Expecting 41600 events.
[13:28:17.448] INFO: 41600 events read in total (2697ms).
[13:28:17.449] INFO: Test took 3933ms.
[13:28:17.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:18.206] INFO: Expecting 41600 events.
[13:28:21.448] INFO: 41600 events read in total (2715ms).
[13:28:21.449] INFO: Test took 3945ms.
[13:28:21.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:22.207] INFO: Expecting 41600 events.
[13:28:25.469] INFO: 41600 events read in total (2735ms).
[13:28:25.470] INFO: Test took 3965ms.
[13:28:25.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:26.227] INFO: Expecting 41600 events.
[13:28:29.475] INFO: 41600 events read in total (2721ms).
[13:28:29.476] INFO: Test took 3950ms.
[13:28:29.512] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:30.233] INFO: Expecting 41600 events.
[13:28:33.491] INFO: 41600 events read in total (2731ms).
[13:28:33.492] INFO: Test took 3961ms.
[13:28:33.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:34.245] INFO: Expecting 41600 events.
[13:28:37.499] INFO: 41600 events read in total (2727ms).
[13:28:37.500] INFO: Test took 3952ms.
[13:28:37.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:38.253] INFO: Expecting 41600 events.
[13:28:41.519] INFO: 41600 events read in total (2739ms).
[13:28:41.520] INFO: Test took 3965ms.
[13:28:41.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:42.274] INFO: Expecting 41600 events.
[13:28:45.539] INFO: 41600 events read in total (2738ms).
[13:28:45.540] INFO: Test took 3965ms.
[13:28:45.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:46.293] INFO: Expecting 41600 events.
[13:28:49.550] INFO: 41600 events read in total (2730ms).
[13:28:49.551] INFO: Test took 3955ms.
[13:28:49.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:50.307] INFO: Expecting 41600 events.
[13:28:53.583] INFO: 41600 events read in total (2749ms).
[13:28:53.584] INFO: Test took 3978ms.
[13:28:53.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:54.342] INFO: Expecting 41600 events.
[13:28:57.600] INFO: 41600 events read in total (2731ms).
[13:28:57.601] INFO: Test took 3962ms.
[13:28:57.637] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:58.356] INFO: Expecting 41600 events.
[13:29:01.610] INFO: 41600 events read in total (2727ms).
[13:29:01.611] INFO: Test took 3955ms.
[13:29:01.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:02.368] INFO: Expecting 41600 events.
[13:29:05.639] INFO: 41600 events read in total (2744ms).
[13:29:05.640] INFO: Test took 3973ms.
[13:29:05.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:06.395] INFO: Expecting 41600 events.
[13:29:09.649] INFO: 41600 events read in total (2727ms).
[13:29:09.650] INFO: Test took 3955ms.
[13:29:09.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:10.406] INFO: Expecting 41600 events.
[13:29:13.667] INFO: 41600 events read in total (2734ms).
[13:29:13.668] INFO: Test took 3962ms.
[13:29:13.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:14.421] INFO: Expecting 41600 events.
[13:29:17.688] INFO: 41600 events read in total (2740ms).
[13:29:17.689] INFO: Test took 3964ms.
[13:29:17.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:18.443] INFO: Expecting 41600 events.
[13:29:21.707] INFO: 41600 events read in total (2737ms).
[13:29:21.708] INFO: Test took 3964ms.
[13:29:21.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:22.463] INFO: Expecting 41600 events.
[13:29:25.703] INFO: 41600 events read in total (2714ms).
[13:29:25.704] INFO: Test took 3941ms.
[13:29:25.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:26.460] INFO: Expecting 41600 events.
[13:29:29.564] INFO: 41600 events read in total (2578ms).
[13:29:29.565] INFO: Test took 3807ms.
[13:29:29.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:29.960] INFO: enter test to run
[13:30:16.268] INFO: test: HighRate no parameter change
[13:30:16.268] INFO: running: highrate
[13:30:16.269] INFO: ----------------------------------------------------------------------
[13:30:16.269] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:30:16.269] INFO: ----------------------------------------------------------------------
[13:30:16.893] INFO: Expecting 208000 events.
[13:30:28.716] INFO: 208000 events read in total (11297ms).
[13:30:28.719] INFO: Test took 12442ms.
[13:30:28.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:29.139] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:30:29.139] INFO: number of red-efficiency pixels: 86 64 85 135 145 139 132 109 78 113 104 113 106 62 18 29
[13:30:29.139] INFO: number of X-ray hits detected: 69819 45138 73515 122131 118879 126937 130214 91061 81878 100723 100835 87674 90361 59076 22740 27084
[13:30:29.139] 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:30:29.139] INFO: number of Vcal hits detected: 207910 207936 207911 207860 207854 207851 207866 207889 207918 207887 207893 207887 207887 207937 207982 207971
[13:30:29.139] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0
[13:30:29.139] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:30:29.139] INFO: X-ray hit rate [MHz/cm2]: 20.5 13.2 21.5 35.8 34.8 37.2 38.2 26.7 24.0 29.5 29.6 25.7 26.5 17.3 6.7 7.9
[13:30:29.139] INFO: PixTestHighRate::doXPixelAlive() done
[13:30:29.183] INFO: PixTest:: pg_setup set to default.
[13:30:29.199] INFO: enter test to run
[13:30:47.155] INFO: test: HighRate no parameter change
[13:30:47.155] INFO: running: highrate
[13:30:47.157] INFO: ----------------------------------------------------------------------
[13:30:47.157] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:30:47.157] INFO: ----------------------------------------------------------------------
[13:30:47.775] INFO: Expecting 208000 events.
[13:31:01.362] INFO: 208000 events read in total (13060ms).
[13:31:01.367] INFO: Test took 14201ms.
[13:31:01.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:01.960] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:31:01.960] INFO: number of red-efficiency pixels: 187 119 209 412 368 433 451 286 226 376 259 298 264 185 57 49
[13:31:01.960] INFO: number of X-ray hits detected: 132976 86222 139060 232090 226140 239638 246328 173132 156203 190963 191516 166733 172459 112796 43692 51615
[13:31:01.960] 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:31:01.960] INFO: number of Vcal hits detected: 207803 207877 207779 207565 207606 207526 207515 207698 207758 207599 207727 207685 207704 207805 207942 207950
[13:31:01.960] 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:31:01.960] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.8 99.9 99.9 100.0 100.0
[13:31:01.960] INFO: X-ray hit rate [MHz/cm2]: 39.0 25.3 40.8 68.0 66.3 70.2 72.2 50.7 45.8 56.0 56.1 48.9 50.5 33.1 12.8 15.1
[13:31:01.960] INFO: PixTestHighRate::doXPixelAlive() done
[13:31:02.007] INFO: PixTest:: pg_setup set to default.
[13:31:02.021] INFO: enter test to run
[13:31:14.963] INFO: test: HighRate no parameter change
[13:31:14.963] INFO: running: highrate
[13:31:14.964] INFO: ----------------------------------------------------------------------
[13:31:14.964] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:31:14.964] INFO: ----------------------------------------------------------------------
[13:31:15.581] INFO: Expecting 208000 events.
[13:31:30.860] INFO: 208000 events read in total (14752ms).
[13:31:30.867] INFO: Test took 15894ms.
[13:31:31.305] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:31.651] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:31:31.651] INFO: number of red-efficiency pixels: 455 257 456 865 788 880 960 670 518 801 581 627 496 366 80 89
[13:31:31.651] INFO: number of X-ray hits detected: 195897 127177 206828 341892 333245 353969 364212 256404 231115 282068 282624 246671 255248 166478 64295 76814
[13:31:31.651] 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:31:31.651] INFO: number of Vcal hits detected: 207488 207725 207456 206956 207087 206930 206837 207190 207418 207066 207347 207294 207408 207591 207916 207909
[13:31:31.651] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.5 99.5 99.6 99.7 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[13:31:31.651] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.6 99.5 99.4 99.6 99.7 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[13:31:31.651] INFO: X-ray hit rate [MHz/cm2]: 57.4 37.3 60.6 100.2 97.7 103.8 106.8 75.2 67.7 82.7 82.8 72.3 74.8 48.8 18.8 22.5
[13:31:31.651] INFO: PixTestHighRate::doXPixelAlive() done
[13:31:31.697] INFO: PixTest:: pg_setup set to default.
[13:31:31.711] INFO: enter test to run
[13:31:34.747] INFO: test: exit no parameter change
[13:31:35.068] QUIET: Connection to board 33 closed.
[13:31:35.068] INFO: pXar: this is the end, my friend