[14:50:46.502] INFO: *** Welcome to pxar ***
[14:50:46.502] INFO: *** Today: 2016/05/02
[14:50:46.523] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:50:46.523] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//dacParameters35_C15.dat
[14:50:46.552] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:50:46.552] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//defaultMaskFile.dat
[14:50:46.558] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C15.dat
[14:50:46.687] INFO: clk: 4
[14:50:46.687] INFO: ctr: 4
[14:50:46.687] INFO: sda: 19
[14:50:46.687] INFO: tin: 9
[14:50:46.687] INFO: level: 15
[14:50:46.687] INFO: triggerdelay: 0
[14:50:46.687] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:50:46.687] INFO: Log level: INFO
[14:50:46.706] QUIET: Connection to board DTB_WREKRL opened.
[14:50:46.709] 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:50:46.712] INFO: RPC call hashes of host and DTB match: 398089610
[14:50:48.243] INFO: DUT info:
[14:50:48.243] INFO: The DUT currently contains the following objects:
[14:50:48.243] INFO: 2 TBM Cores tbm08c (2 ON)
[14:50:48.243] INFO: TBM Core alpha (0): 7 registers set
[14:50:48.243] INFO: TBM Core beta (1): 7 registers set
[14:50:48.243] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:50:48.243] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.243] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.244] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:48.647] INFO: enter 'restricted' command line mode
[14:50:48.647] INFO: enter test to run
[14:50:57.859] INFO: test: PixelAlive no parameter change
[14:50:57.859] INFO: running: pixelalive
[14:50:57.868] INFO: ----------------------------------------------------------------------
[14:50:57.868] 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:50:57.869] INFO: ----------------------------------------------------------------------
[14:50:58.186] INFO: Expecting 41600 events.
[14:51:02.505] INFO: 41600 events read in total (3601ms).
[14:51:02.675] INFO: Test took 4804ms.
[14:51:02.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:02.948] INFO: PixTestAlive::aliveTest() done
[14:51:02.948] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:51:02.980] INFO: enter test to run
[14:51:30.235] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:51:30.235] INFO: running: highrate
[14:51:30.236] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:51:30.549] INFO: ----------------------------------------------------------------------
[14:51:30.549] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:51:30.549] INFO: ----------------------------------------------------------------------
[14:51:30.549] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:51:30.549] INFO: edge/corner pixel THR is adjusted
[14:51:30.549] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:51:31.507] INFO: Collecting data for 5 seconds...
[14:51:36.519] INFO: Done with hot pixel readout
[14:51:48.047] INFO: PixTest:: pg_setup set to default.
[14:51:48.048] INFO: 23 hot pixels found in step 0
[14:51:49.036] INFO: Collecting data for 5 seconds...
[14:51:54.052] INFO: Done with hot pixel readout
[14:52:05.624] INFO: PixTest:: pg_setup set to default.
[14:52:05.625] INFO: 22 hot pixels found in step 1
[14:52:06.619] INFO: Collecting data for 5 seconds...
[14:52:11.635] INFO: Done with hot pixel readout
[14:52:23.239] INFO: PixTest:: pg_setup set to default.
[14:52:23.240] INFO: 22 hot pixels found in step 2
[14:52:24.231] INFO: Collecting data for 5 seconds...
[14:52:29.247] INFO: Done with hot pixel readout
[14:52:40.851] INFO: PixTest:: pg_setup set to default.
[14:52:40.852] INFO: 23 hot pixels found in step 3
[14:52:41.844] INFO: Collecting data for 5 seconds...
[14:52:46.861] INFO: Done with hot pixel readout
[14:52:58.470] INFO: PixTest:: pg_setup set to default.
[14:52:58.471] INFO: 25 hot pixels found in step 4
[14:52:59.463] INFO: Collecting data for 5 seconds...
[14:53:04.480] INFO: Done with hot pixel readout
[14:53:16.073] INFO: PixTest:: pg_setup set to default.
[14:53:16.074] INFO: 21 hot pixels found in step 5
[14:53:17.065] INFO: Collecting data for 5 seconds...
[14:53:22.081] INFO: Done with hot pixel readout
[14:53:33.653] INFO: PixTest:: pg_setup set to default.

[14:53:33.654] INFO: 21 hot pixels found in step 6
[14:53:34.646] INFO: Collecting data for 5 seconds...
[14:53:39.663] INFO: Done with hot pixel readout
[14:53:51.267] INFO: PixTest:: pg_setup set to default.



[14:53:51.268] INFO: 19 hot pixels found in step 7
[14:53:52.259] INFO: Collecting data for 5 seconds...
[14:53:57.275] INFO: Done with hot pixel readout
[14:54:08.897] INFO: PixTest:: pg_setup set to default.



[14:54:08.898] INFO: 22 hot pixels found in step 8
[14:54:09.889] INFO: Collecting data for 5 seconds...
[14:54:14.905] INFO: Done with hot pixel readout
[14:54:26.479] INFO: PixTest:: pg_setup set to default.







[14:54:26.480] INFO: 14 hot pixels found in step 9
[14:54:27.471] INFO: Collecting data for 5 seconds...
[14:54:32.488] INFO: Done with hot pixel readout
[14:54:44.121] INFO: PixTest:: pg_setup set to default.








[14:54:44.122] INFO: 16 hot pixels found in step 10
[14:54:45.114] INFO: Collecting data for 5 seconds...
[14:54:50.131] INFO: Done with hot pixel readout
[14:55:01.737] INFO: PixTest:: pg_setup set to default.









[14:55:01.738] INFO: 14 hot pixels found in step 11
[14:55:02.730] INFO: Collecting data for 5 seconds...
[14:55:07.745] INFO: Done with hot pixel readout
[14:55:19.373] INFO: PixTest:: pg_setup set to default.









[14:55:19.374] INFO: 15 hot pixels found in step 12
[14:55:20.366] INFO: Collecting data for 5 seconds...
[14:55:25.382] INFO: Done with hot pixel readout
[14:55:37.013] INFO: PixTest:: pg_setup set to default.








[14:55:37.014] INFO: 10 hot pixels found in step 13
[14:55:38.005] INFO: Collecting data for 5 seconds...
[14:55:43.021] INFO: Done with hot pixel readout
[14:55:54.580] INFO: PixTest:: pg_setup set to default.












[14:55:54.581] INFO: 16 hot pixels found in step 14
[14:55:54.617] INFO: 16 hot pixels could not be trimmed and have been masked.
[14:55:54.620] INFO: PixTest::trimHotPixels() done
[14:55:54.620] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C0.dat
[14:55:54.626] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C1.dat
[14:55:54.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C2.dat
[14:55:54.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C3.dat
[14:55:54.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C4.dat
[14:55:54.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C5.dat
[14:55:54.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C6.dat
[14:55:54.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C7.dat
[14:55:54.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C8.dat
[14:55:54.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C9.dat
[14:55:54.674] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C10.dat
[14:55:54.679] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C11.dat
[14:55:54.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C12.dat
[14:55:54.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C13.dat
[14:55:54.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C14.dat
[14:55:54.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C15.dat
[14:55:54.705] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//defaultMaskFile.dat
[14:55:54.715] INFO: enter test to run
[14:56:16.785] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:56:16.785] INFO: running: highrate
[14:56:16.789] INFO: ----------------------------------------------------------------------
[14:56:16.790] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:56:16.790] INFO: ----------------------------------------------------------------------
[14:56:16.790] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:56:16.790] INFO: edge/corner pixel THR is adjusted
[14:56:16.790] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:56:17.748] INFO: Collecting data for 1 seconds...
[14:56:18.752] INFO: Done with hot pixel readout
[14:56:22.755] INFO: PixTest:: pg_setup set to default.
[14:56:22.756] INFO: 0 hot pixels found in step 0
[14:56:22.761] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:56:22.850] INFO: PixTest::trimHotPixels() done
[14:56:22.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C0.dat
[14:56:22.862] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C1.dat
[14:56:22.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C2.dat
[14:56:22.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C3.dat
[14:56:22.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C4.dat
[14:56:22.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C5.dat
[14:56:22.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C6.dat
[14:56:22.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C7.dat
[14:56:22.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C8.dat
[14:56:22.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C9.dat
[14:56:22.911] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C10.dat
[14:56:22.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C11.dat
[14:56:22.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C12.dat
[14:56:22.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C13.dat
[14:56:22.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C14.dat
[14:56:22.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//trimParameters35_C15.dat
[14:56:22.942] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160425-1325_2016-04-25_13h25m_1461608735/000_FPIXTest_p17//defaultMaskFile.dat
[14:56:22.952] INFO: enter test to run
[14:56:54.353] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:56:54.353] INFO: running: xray
[14:56:54.354] INFO: ----------------------------------------------------------------------
[14:56:54.354] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:56:54.354] INFO: ----------------------------------------------------------------------
[14:56:55.317] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:57:06.754] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:57:36.151] INFO: Resuming triggers.
[14:57:47.587] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:58:17.017] INFO: Resuming triggers.
[14:58:28.451] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:58:57.766] INFO: Resuming triggers.
[14:59:09.200] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:59:38.624] INFO: Resuming triggers.
[14:59:50.061] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:00:19.450] INFO: Resuming triggers.
[15:00:30.885] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:01:00.262] INFO: Resuming triggers.
[15:01:11.700] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:01:37.591] INFO: Resuming triggers.
[15:01:49.029] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:02:18.312] INFO: Resuming triggers.
[15:02:27.147] INFO: data taking finished, elapsed time: 100 seconds.
[15:02:49.910] INFO: PixTest:: pg_setup set to default.
[15:02:49.914] INFO: PixTestXray::doPhRun() done
[15:02:50.049] INFO: enter test to run
[15:03:16.326] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:03:16.326] INFO: running: xray
[15:03:16.327] INFO: ----------------------------------------------------------------------
[15:03:16.327] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:03:16.327] INFO: ----------------------------------------------------------------------
[15:03:17.302] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:03:23.900] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:03:53.960] INFO: Resuming triggers.
[15:04:00.554] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:04:30.599] INFO: Resuming triggers.
[15:04:37.192] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:05:07.253] INFO: Resuming triggers.
[15:05:13.850] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:05:43.943] INFO: Resuming triggers.
[15:05:50.538] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:06:20.685] INFO: Resuming triggers.
[15:06:27.283] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:06:57.386] INFO: Resuming triggers.
[15:07:03.985] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:07:34.107] INFO: Resuming triggers.
[15:07:40.707] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:08:10.809] INFO: Resuming triggers.
[15:08:17.409] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:08:47.240] INFO: Resuming triggers.
[15:08:53.839] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:09:23.933] INFO: Resuming triggers.
[15:09:30.530] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:10:00.905] INFO: Resuming triggers.
[15:10:07.503] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:10:37.234] INFO: Resuming triggers.
[15:10:43.832] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:11:14.127] INFO: Resuming triggers.
[15:11:20.728] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:11:47.437] INFO: Resuming triggers.
[15:11:54.040] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[15:12:24.044] INFO: Resuming triggers.
[15:12:25.398] INFO: data taking finished, elapsed time: 100 seconds.
[15:12:31.925] INFO: PixTest:: pg_setup set to default.
[15:12:31.928] INFO: PixTestXray::doPhRun() done
[15:12:32.076] INFO: enter test to run
[15:13:07.993] INFO: test: HighRate no parameter change
[15:13:07.993] INFO: running: highrate
[15:13:07.995] INFO: ----------------------------------------------------------------------
[15:13:07.995] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:13:07.995] INFO: ----------------------------------------------------------------------
[15:13:08.134] INFO: Expecting 768 events.
[15:13:09.268] INFO: 768 events read in total (418ms).
[15:13:09.268] INFO: Test took 1267ms.
[15:13:10.072] INFO: Expecting 41600 events.
[15:13:13.152] INFO: 41600 events read in total (2553ms).
[15:13:13.154] INFO: Test took 3878ms.
[15:13:13.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:13.913] INFO: Expecting 41600 events.
[15:13:17.101] INFO: 41600 events read in total (2661ms).
[15:13:17.102] INFO: Test took 3900ms.
[15:13:17.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:17.863] INFO: Expecting 41600 events.
[15:13:21.076] INFO: 41600 events read in total (2687ms).
[15:13:21.077] INFO: Test took 3926ms.
[15:13:21.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:21.828] INFO: Expecting 41600 events.
[15:13:25.024] INFO: 41600 events read in total (2669ms).
[15:13:25.025] INFO: Test took 3899ms.
[15:13:25.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:25.786] INFO: Expecting 41600 events.
[15:13:29.006] INFO: 41600 events read in total (2693ms).
[15:13:29.007] INFO: Test took 3935ms.
[15:13:29.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:29.768] INFO: Expecting 41600 events.
[15:13:32.981] INFO: 41600 events read in total (2686ms).
[15:13:32.982] INFO: Test took 3927ms.
[15:13:33.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:33.745] INFO: Expecting 41600 events.
[15:13:36.952] INFO: 41600 events read in total (2681ms).
[15:13:36.953] INFO: Test took 3922ms.
[15:13:36.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:37.715] INFO: Expecting 41600 events.
[15:13:40.937] INFO: 41600 events read in total (2695ms).
[15:13:40.938] INFO: Test took 3937ms.
[15:13:40.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:41.700] INFO: Expecting 41600 events.
[15:13:44.916] INFO: 41600 events read in total (2689ms).
[15:13:44.917] INFO: Test took 3930ms.
[15:13:44.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:45.675] INFO: Expecting 41600 events.
[15:13:48.881] INFO: 41600 events read in total (2679ms).
[15:13:48.882] INFO: Test took 3915ms.
[15:13:48.913] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:49.645] INFO: Expecting 41600 events.
[15:13:52.864] INFO: 41600 events read in total (2692ms).
[15:13:52.865] INFO: Test took 3933ms.
[15:13:52.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:53.626] INFO: Expecting 41600 events.
[15:13:56.858] INFO: 41600 events read in total (2705ms).
[15:13:56.859] INFO: Test took 3946ms.
[15:13:56.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:57.618] INFO: Expecting 41600 events.
[15:14:00.840] INFO: 41600 events read in total (2695ms).
[15:14:00.841] INFO: Test took 3934ms.
[15:14:00.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:01.599] INFO: Expecting 41600 events.
[15:14:04.805] INFO: 41600 events read in total (2679ms).
[15:14:04.806] INFO: Test took 3915ms.
[15:14:04.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:05.568] INFO: Expecting 41600 events.
[15:14:08.776] INFO: 41600 events read in total (2681ms).
[15:14:08.777] INFO: Test took 3923ms.
[15:14:08.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:09.539] INFO: Expecting 41600 events.
[15:14:12.747] INFO: 41600 events read in total (2681ms).
[15:14:12.748] INFO: Test took 3922ms.
[15:14:12.780] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:13.510] INFO: Expecting 41600 events.
[15:14:16.727] INFO: 41600 events read in total (2690ms).
[15:14:16.728] INFO: Test took 3931ms.
[15:14:16.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:17.485] INFO: Expecting 41600 events.
[15:14:20.701] INFO: 41600 events read in total (2690ms).
[15:14:20.702] INFO: Test took 3925ms.
[15:14:20.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:21.463] INFO: Expecting 41600 events.
[15:14:24.660] INFO: 41600 events read in total (2671ms).
[15:14:24.661] INFO: Test took 3910ms.
[15:14:24.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:25.419] INFO: Expecting 41600 events.
[15:14:28.473] INFO: 41600 events read in total (2528ms).
[15:14:28.474] INFO: Test took 3763ms.
[15:14:28.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:28.875] INFO: enter test to run
[15:14:44.313] INFO: test: HighRate no parameter change
[15:14:44.313] INFO: running: highrate
[15:14:44.338] INFO: ----------------------------------------------------------------------
[15:14:44.338] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:14:44.338] INFO: ----------------------------------------------------------------------
[15:14:44.952] INFO: Expecting 208000 events.
[15:14:56.695] INFO: 208000 events read in total (11216ms).
[15:14:56.698] INFO: Test took 12350ms.
[15:14:56.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:57.075] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:14:57.075] INFO: number of red-efficiency pixels: 72 45 63 120 126 140 135 86 79 127 126 80 115 50 27 23
[15:14:57.075] INFO: number of X-ray hits detected: 63736 40643 61955 96370 105424 107191 102442 73925 66805 83149 86329 74492 77141 46368 20649 21974
[15:14:57.075] 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:14:57.075] INFO: number of Vcal hits detected: 207927 207954 207936 207879 207873 207859 207861 207913 207920 207871 207871 207917 207883 207949 207973 207976
[15:14:57.075] 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 99.9 100.0 99.9 100.0 100.0 100.0
[15:14:57.075] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[15:14:57.075] INFO: X-ray hit rate [MHz/cm2]: 18.7 11.9 18.2 28.2 30.9 31.4 30.0 21.7 19.6 24.4 25.3 21.8 22.6 13.6 6.1 6.4
[15:14:57.075] INFO: PixTestHighRate::doXPixelAlive() done
[15:14:57.125] INFO: PixTest:: pg_setup set to default.
[15:14:57.139] INFO: enter test to run
[15:15:18.696] INFO: test: HighRate no parameter change
[15:15:18.697] INFO: running: highrate
[15:15:18.698] INFO: ----------------------------------------------------------------------
[15:15:18.698] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:15:18.698] INFO: ----------------------------------------------------------------------
[15:15:19.318] INFO: Expecting 208000 events.
[15:15:33.100] INFO: 208000 events read in total (13255ms).
[15:15:33.106] INFO: Test took 14400ms.
[15:15:33.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:33.717] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:15:33.717] INFO: number of red-efficiency pixels: 208 152 318 540 536 500 544 361 260 409 443 326 359 189 52 64
[15:15:33.717] INFO: number of X-ray hits detected: 149424 97055 147655 228871 248998 253967 242338 174611 157751 196336 204272 175797 183049 109272 49098 51977
[15:15:33.717] 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:15:33.717] INFO: number of Vcal hits detected: 207780 207844 207644 207411 207406 207444 207406 207603 207731 207552 207526 207655 207610 207798 207948 207935
[15:15:33.718] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:15:33.718] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:15:33.718] INFO: X-ray hit rate [MHz/cm2]: 43.8 28.4 43.3 67.1 73.0 74.4 71.0 51.2 46.2 57.5 59.9 51.5 53.7 32.0 14.4 15.2
[15:15:33.718] INFO: PixTestHighRate::doXPixelAlive() done
[15:15:33.767] INFO: PixTest:: pg_setup set to default.
[15:15:33.779] INFO: enter test to run
[15:15:54.992] INFO: test: HighRate no parameter change
[15:15:54.992] INFO: running: highrate
[15:15:54.993] INFO: ----------------------------------------------------------------------
[15:15:54.993] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:15:54.993] INFO: ----------------------------------------------------------------------
[15:15:55.609] INFO: Expecting 208000 events.
[15:16:11.180] INFO: 208000 events read in total (15044ms).
[15:16:11.187] INFO: Test took 16185ms.
[15:16:11.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:12.003] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:16:12.003] INFO: number of red-efficiency pixels: 442 284 684 1137 1189 1063 1281 795 560 834 966 722 829 413 100 78
[15:16:12.003] INFO: number of X-ray hits detected: 221280 142791 219869 338210 367377 375067 359520 259916 235535 290794 303519 259583 272449 162537 73037 77877
[15:16:12.003] 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:16:12.003] INFO: number of Vcal hits detected: 207458 207697 207080 206608 206461 206642 206309 207028 207378 207016 206828 207158 207028 207529 207897 207919
[15:16:12.003] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.3 99.4 99.3 99.6 99.7 99.6 99.5 99.6 99.6 99.8 100.0 100.0
[15:16:12.003] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.3 99.3 99.3 99.2 99.5 99.7 99.5 99.4 99.6 99.5 99.8 100.0 100.0
[15:16:12.003] INFO: X-ray hit rate [MHz/cm2]: 64.9 41.9 64.4 99.1 107.7 109.9 105.4 76.2 69.0 85.2 89.0 76.1 79.9 47.6 21.4 22.8
[15:16:12.003] INFO: PixTestHighRate::doXPixelAlive() done
[15:16:12.051] INFO: PixTest:: pg_setup set to default.
[15:16:12.069] INFO: enter test to run
[15:17:10.511] INFO: test: exit no parameter change
[15:17:10.907] QUIET: Connection to board 33 closed.
[15:17:10.908] INFO: pXar: this is the end, my friend