[12:02:56.867] INFO: *** Welcome to pxar ***
[12:02:56.867] INFO: *** Today: 2016/06/16
[12:02:56.887] INFO: *** Version: v1.9.0-814-g7497
[12:02:56.887] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//dacParameters35_C15.dat
[12:02:56.918] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:02:56.919] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//defaultMaskFile.dat
[12:02:56.927] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C15.dat
[12:02:57.029] INFO: clk: 4
[12:02:57.029] INFO: ctr: 4
[12:02:57.029] INFO: sda: 19
[12:02:57.029] INFO: tin: 9
[12:02:57.029] INFO: level: 15
[12:02:57.029] INFO: triggerdelay: 0
[12:02:57.029] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:02:57.029] INFO: Log level: INFO
[12:02:57.047] QUIET: Connection to board DTB_WREKRL opened.
[12:02:57.050] 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:
------------------------------------------------------
[12:02:57.053] INFO: RPC call hashes of host and DTB match: 398089610
[12:02:58.585] INFO: DUT info:
[12:02:58.585] INFO: The DUT currently contains the following objects:
[12:02:58.585] INFO: 2 TBM Cores tbm08c (2 ON)
[12:02:58.585] INFO: TBM Core alpha (0): 7 registers set
[12:02:58.585] INFO: TBM Core beta (1): 7 registers set
[12:02:58.585] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:02:58.585] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.585] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.586] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.586] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.586] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.586] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.586] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.586] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:58.989] INFO: enter 'restricted' command line mode
[12:02:58.989] INFO: enter test to run
[12:03:06.938] INFO: test: PixelAlive no parameter change
[12:03:06.938] INFO: running: pixelalive
[12:03:06.947] INFO: ----------------------------------------------------------------------
[12:03:06.947] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:03:06.947] INFO: ----------------------------------------------------------------------
[12:03:07.265] INFO: Expecting 41600 events.
[12:03:11.614] INFO: 41600 events read in total (3631ms).
[12:03:11.775] INFO: Test took 4825ms.
[12:03:11.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:12.060] INFO: PixTestAlive::aliveTest() done
[12:03:12.060] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[12:03:12.093] INFO: enter test to run
[12:03:51.137] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:03:51.138] INFO: running: highrate
[12:03:51.138] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:03:51.364] INFO: ----------------------------------------------------------------------
[12:03:51.364] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:03:51.364] INFO: ----------------------------------------------------------------------
[12:03:51.364] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:03:51.364] INFO: edge/corner pixel THR is adjusted
[12:03:51.364] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:03:52.323] INFO: Collecting data for 5 seconds...
[12:03:57.340] INFO: Done with hot pixel readout
[12:04:09.192] INFO: PixTest:: pg_setup set to default.
[12:04:09.193] INFO: 46 hot pixels found in step 0
[12:04:10.188] INFO: Collecting data for 5 seconds...
[12:04:15.204] INFO: Done with hot pixel readout
[12:04:26.996] INFO: PixTest:: pg_setup set to default.


[12:04:26.997] INFO: 38 hot pixels found in step 1
[12:04:27.991] INFO: Collecting data for 5 seconds...
[12:04:33.006] INFO: Done with hot pixel readout
[12:04:44.733] INFO: PixTest:: pg_setup set to default.

[12:04:44.733] INFO: 45 hot pixels found in step 2
[12:04:45.725] INFO: Collecting data for 5 seconds...
[12:04:50.741] INFO: Done with hot pixel readout
[12:05:02.540] INFO: PixTest:: pg_setup set to default.

[12:05:02.541] INFO: 36 hot pixels found in step 3
[12:05:03.533] INFO: Collecting data for 5 seconds...
[12:05:08.549] INFO: Done with hot pixel readout
[12:05:20.354] INFO: PixTest:: pg_setup set to default.
[12:05:20.355] INFO: 32 hot pixels found in step 4
[12:05:21.347] INFO: Collecting data for 5 seconds...
[12:05:26.362] INFO: Done with hot pixel readout
[12:05:38.230] INFO: PixTest:: pg_setup set to default.





[12:05:38.231] INFO: 32 hot pixels found in step 5
[12:05:39.225] INFO: Collecting data for 5 seconds...
[12:05:44.240] INFO: Done with hot pixel readout
[12:05:56.073] INFO: PixTest:: pg_setup set to default.




[12:05:56.074] INFO: 31 hot pixels found in step 6
[12:05:57.065] INFO: Collecting data for 5 seconds...
[12:06:02.081] INFO: Done with hot pixel readout
[12:06:13.883] INFO: PixTest:: pg_setup set to default.





[12:06:13.884] INFO: 22 hot pixels found in step 7
[12:06:14.875] INFO: Collecting data for 5 seconds...
[12:06:19.891] INFO: Done with hot pixel readout
[12:06:31.723] INFO: PixTest:: pg_setup set to default.






[12:06:31.724] INFO: 25 hot pixels found in step 8
[12:06:32.715] INFO: Collecting data for 5 seconds...
[12:06:37.730] INFO: Done with hot pixel readout
[12:06:49.523] INFO: PixTest:: pg_setup set to default.






[12:06:49.524] INFO: 26 hot pixels found in step 9
[12:06:50.516] INFO: Collecting data for 5 seconds...
[12:06:55.531] INFO: Done with hot pixel readout
[12:07:07.343] INFO: PixTest:: pg_setup set to default.





[12:07:07.344] INFO: 17 hot pixels found in step 10
[12:07:08.336] INFO: Collecting data for 5 seconds...
[12:07:13.351] INFO: Done with hot pixel readout
[12:07:25.162] INFO: PixTest:: pg_setup set to default.






[12:07:25.163] INFO: 30 hot pixels found in step 11
[12:07:26.154] INFO: Collecting data for 5 seconds...
[12:07:31.170] INFO: Done with hot pixel readout
[12:07:43.016] INFO: PixTest:: pg_setup set to default.





[12:07:43.017] INFO: 15 hot pixels found in step 12
[12:07:44.009] INFO: Collecting data for 5 seconds...
[12:07:49.024] INFO: Done with hot pixel readout
[12:08:00.858] INFO: PixTest:: pg_setup set to default.





[12:08:00.859] INFO: 20 hot pixels found in step 13
[12:08:01.851] INFO: Collecting data for 5 seconds...
[12:08:06.866] INFO: Done with hot pixel readout
[12:08:18.667] INFO: PixTest:: pg_setup set to default.




[12:08:18.668] INFO: 20 hot pixels found in step 14
[12:08:18.703] INFO: 20 hot pixels could not be trimmed and have been masked.
[12:08:18.707] INFO: PixTest::trimHotPixels() done
[12:08:18.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C0.dat
[12:08:18.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C1.dat
[12:08:18.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C2.dat
[12:08:18.725] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C3.dat
[12:08:18.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C4.dat
[12:08:18.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C5.dat
[12:08:18.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C6.dat
[12:08:18.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C7.dat
[12:08:18.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C8.dat
[12:08:18.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C9.dat
[12:08:18.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C10.dat
[12:08:18.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C11.dat
[12:08:18.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C12.dat
[12:08:18.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C13.dat
[12:08:18.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C14.dat
[12:08:18.787] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C15.dat
[12:08:18.792] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//defaultMaskFile.dat
[12:08:18.803] INFO: enter test to run
[12:08:52.855] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:08:52.855] INFO: running: highrate
[12:08:52.860] INFO: ----------------------------------------------------------------------
[12:08:52.860] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:08:52.860] INFO: ----------------------------------------------------------------------
[12:08:52.860] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:08:52.860] INFO: edge/corner pixel THR is adjusted
[12:08:52.860] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:08:53.818] INFO: Collecting data for 1 seconds...
[12:08:54.822] INFO: Done with hot pixel readout
[12:08:58.932] INFO: PixTest:: pg_setup set to default.
[12:08:58.933] INFO: 0 hot pixels found in step 0
[12:08:58.938] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:08:59.026] INFO: PixTest::trimHotPixels() done
[12:08:59.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C0.dat
[12:08:59.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C1.dat
[12:08:59.045] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C2.dat
[12:08:59.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C3.dat
[12:08:59.056] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C4.dat
[12:08:59.061] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C5.dat
[12:08:59.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C6.dat
[12:08:59.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C7.dat
[12:08:59.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C8.dat
[12:08:59.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C9.dat
[12:08:59.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C10.dat
[12:08:59.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C11.dat
[12:08:59.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C12.dat
[12:08:59.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C13.dat
[12:08:59.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C14.dat
[12:08:59.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//trimParameters35_C15.dat
[12:08:59.120] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-41_FPIXTest-17C-FNAL-160610-1511_2016-06-10_15h11m_1465589481/000_FPIXTest_p17//defaultMaskFile.dat
[12:08:59.130] INFO: enter test to run
[12:09:36.255] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:09:36.255] INFO: running: xray
[12:09:36.256] INFO: ----------------------------------------------------------------------
[12:09:36.256] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:09:36.257] INFO: ----------------------------------------------------------------------
[12:09:37.220] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:09:48.559] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:10:17.970] INFO: Resuming triggers.
[12:10:29.309] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:10:58.695] INFO: Resuming triggers.
[12:11:10.040] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:11:39.449] INFO: Resuming triggers.
[12:11:50.790] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:12:20.205] INFO: Resuming triggers.
[12:12:31.549] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:13:01.046] INFO: Resuming triggers.
[12:13:12.390] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:13:41.898] INFO: Resuming triggers.
[12:13:53.239] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:14:22.635] INFO: Resuming triggers.
[12:14:33.973] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:15:03.322] INFO: Resuming triggers.
[12:15:12.897] INFO: data taking finished, elapsed time: 100 seconds.
[12:15:37.850] INFO: PixTest:: pg_setup set to default.
[12:15:37.853] INFO: PixTestXray::doPhRun() done
[12:15:38.028] INFO: enter test to run
[12:16:20.260] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:16:20.260] INFO: running: xray
[12:16:20.261] INFO: ----------------------------------------------------------------------
[12:16:20.261] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:16:20.261] INFO: ----------------------------------------------------------------------
[12:16:21.225] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:16:27.790] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:16:58.081] INFO: Resuming triggers.
[12:17:04.646] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:17:34.865] INFO: Resuming triggers.
[12:17:41.433] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:18:11.719] INFO: Resuming triggers.
[12:18:18.284] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:18:48.516] INFO: Resuming triggers.
[12:18:55.084] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:19:25.359] INFO: Resuming triggers.
[12:19:31.927] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:20:02.126] INFO: Resuming triggers.
[12:20:08.695] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:20:39.075] INFO: Resuming triggers.
[12:20:45.648] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:21:15.930] INFO: Resuming triggers.
[12:21:22.499] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:21:52.740] INFO: Resuming triggers.
[12:21:59.309] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:22:29.551] INFO: Resuming triggers.
[12:22:36.125] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:23:06.448] INFO: Resuming triggers.
[12:23:13.021] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[12:23:43.241] INFO: Resuming triggers.
[12:23:49.810] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:24:20.052] INFO: Resuming triggers.
[12:24:26.620] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:24:56.682] INFO: Resuming triggers.
[12:25:03.253] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:25:33.529] INFO: Resuming triggers.
[12:25:35.303] INFO: data taking finished, elapsed time: 100 seconds.
[12:25:43.842] INFO: PixTest:: pg_setup set to default.
[12:25:43.845] INFO: PixTestXray::doPhRun() done
[12:25:43.000] INFO: enter test to run
[12:26:34.392] INFO: test: HighRate no parameter change
[12:26:34.392] INFO: running: highrate
[12:26:34.393] INFO: ----------------------------------------------------------------------
[12:26:34.394] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:26:34.394] INFO: ----------------------------------------------------------------------
[12:26:34.535] INFO: Expecting 768 events.
[12:26:35.669] INFO: 768 events read in total (419ms).
[12:26:35.669] INFO: Test took 1269ms.
[12:26:36.472] INFO: Expecting 41600 events.
[12:26:39.502] INFO: 41600 events read in total (2503ms).
[12:26:39.503] INFO: Test took 3826ms.
[12:26:39.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:40.267] INFO: Expecting 41600 events.
[12:26:43.463] INFO: 41600 events read in total (2670ms).
[12:26:43.464] INFO: Test took 3911ms.
[12:26:43.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:44.223] INFO: Expecting 41600 events.
[12:26:47.458] INFO: 41600 events read in total (2708ms).
[12:26:47.459] INFO: Test took 3942ms.
[12:26:47.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:48.214] INFO: Expecting 41600 events.
[12:26:51.459] INFO: 41600 events read in total (2719ms).
[12:26:51.460] INFO: Test took 3948ms.
[12:26:51.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:52.218] INFO: Expecting 41600 events.
[12:26:55.462] INFO: 41600 events read in total (2717ms).
[12:26:55.463] INFO: Test took 3950ms.
[12:26:55.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:56.217] INFO: Expecting 41600 events.
[12:26:59.463] INFO: 41600 events read in total (2719ms).
[12:26:59.464] INFO: Test took 3947ms.
[12:26:59.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:00.223] INFO: Expecting 41600 events.
[12:27:03.491] INFO: 41600 events read in total (2741ms).
[12:27:03.492] INFO: Test took 3975ms.
[12:27:03.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:04.247] INFO: Expecting 41600 events.
[12:27:07.499] INFO: 41600 events read in total (2725ms).
[12:27:07.500] INFO: Test took 3956ms.
[12:27:07.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:08.253] INFO: Expecting 41600 events.
[12:27:11.509] INFO: 41600 events read in total (2729ms).
[12:27:11.510] INFO: Test took 3948ms.
[12:27:11.545] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:12.268] INFO: Expecting 41600 events.
[12:27:15.529] INFO: 41600 events read in total (2734ms).
[12:27:15.530] INFO: Test took 3966ms.
[12:27:15.565] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:16.286] INFO: Expecting 41600 events.
[12:27:19.535] INFO: 41600 events read in total (2722ms).
[12:27:19.536] INFO: Test took 3952ms.
[12:27:19.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:20.291] INFO: Expecting 41600 events.
[12:27:23.543] INFO: 41600 events read in total (2725ms).
[12:27:23.544] INFO: Test took 3954ms.
[12:27:23.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:24.301] INFO: Expecting 41600 events.
[12:27:27.555] INFO: 41600 events read in total (2728ms).
[12:27:27.556] INFO: Test took 3959ms.
[12:27:27.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:28.315] INFO: Expecting 41600 events.
[12:27:31.562] INFO: 41600 events read in total (2720ms).
[12:27:31.563] INFO: Test took 3954ms.
[12:27:31.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:32.320] INFO: Expecting 41600 events.
[12:27:35.568] INFO: 41600 events read in total (2721ms).
[12:27:35.569] INFO: Test took 3952ms.
[12:27:35.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:36.325] INFO: Expecting 41600 events.
[12:27:39.578] INFO: 41600 events read in total (2726ms).
[12:27:39.579] INFO: Test took 3957ms.
[12:27:39.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:40.335] INFO: Expecting 41600 events.
[12:27:43.587] INFO: 41600 events read in total (2725ms).
[12:27:43.588] INFO: Test took 3954ms.
[12:27:43.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:44.347] INFO: Expecting 41600 events.
[12:27:47.602] INFO: 41600 events read in total (2728ms).
[12:27:47.603] INFO: Test took 3960ms.
[12:27:47.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:48.357] INFO: Expecting 41600 events.
[12:27:51.613] INFO: 41600 events read in total (2730ms).
[12:27:51.614] INFO: Test took 3956ms.
[12:27:51.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:52.372] INFO: Expecting 41600 events.
[12:27:55.545] INFO: 41600 events read in total (2647ms).
[12:27:55.546] INFO: Test took 3878ms.
[12:27:55.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:55.941] INFO: enter test to run
[12:28:03.584] INFO: test: HighRate no parameter change
[12:28:03.584] INFO: running: highrate
[12:28:03.585] INFO: ----------------------------------------------------------------------
[12:28:03.585] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:28:03.585] INFO: ----------------------------------------------------------------------
[12:28:04.203] INFO: Expecting 208000 events.
[12:28:16.126] INFO: 208000 events read in total (11398ms).
[12:28:16.130] INFO: Test took 12537ms.
[12:28:16.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:16.536] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[12:28:16.536] INFO: number of red-efficiency pixels: 96 38 63 126 185 160 136 103 98 145 134 125 138 57 180 24
[12:28:16.536] INFO: number of X-ray hits detected: 70119 46174 68846 114691 116504 122898 120793 82136 74525 100454 97847 86821 91312 52687 20447 23276
[12:28:16.536] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:28:16.536] INFO: number of Vcal hits detected: 207902 207962 207935 207869 207813 207834 207856 207842 207901 207852 207864 207871 207859 207942 207813 207976
[12:28:16.536] 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 99.9 99.9 100.0 99.9 100.0
[12:28:16.536] 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 99.9 100.0
[12:28:16.536] INFO: X-ray hit rate [MHz/cm2]: 20.6 13.5 20.2 33.6 34.1 36.0 35.4 24.1 21.8 29.4 28.7 25.4 26.8 15.4 6.0 6.8
[12:28:16.536] INFO: PixTestHighRate::doXPixelAlive() done
[12:28:16.593] INFO: PixTest:: pg_setup set to default.
[12:28:16.603] INFO: enter test to run
[12:28:41.535] INFO: test: HighRate no parameter change
[12:28:41.535] INFO: running: highrate
[12:28:41.536] INFO: ----------------------------------------------------------------------
[12:28:41.536] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:28:41.536] INFO: ----------------------------------------------------------------------
[12:28:42.148] INFO: Expecting 208000 events.
[12:28:55.858] INFO: 208000 events read in total (13183ms).
[12:28:55.863] INFO: Test took 14317ms.
[12:28:56.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:56.473] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[12:28:56.473] INFO: number of red-efficiency pixels: 279 109 239 477 544 598 476 315 252 399 356 363 345 131 207 65
[12:28:56.473] INFO: number of X-ray hits detected: 142793 93665 140251 233271 238361 249060 245704 167613 152322 203130 198091 178104 185328 107384 41863 46674
[12:28:56.473] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:28:56.473] INFO: number of Vcal hits detected: 207700 207890 207741 207482 207396 207336 207483 207601 207733 207572 207611 207615 207637 207862 207789 207935
[12:28:56.473] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 99.9 100.0
[12:28:56.473] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 99.9 100.0
[12:28:56.473] INFO: X-ray hit rate [MHz/cm2]: 41.9 27.5 41.1 68.4 69.9 73.0 72.0 49.1 44.6 59.5 58.1 52.2 54.3 31.5 12.3 13.7
[12:28:56.473] INFO: PixTestHighRate::doXPixelAlive() done
[12:28:56.520] INFO: PixTest:: pg_setup set to default.
[12:28:56.536] INFO: enter test to run
[12:29:17.255] INFO: test: HighRate no parameter change
[12:29:17.255] INFO: running: highrate
[12:29:17.256] INFO: ----------------------------------------------------------------------
[12:29:17.256] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:29:17.256] INFO: ----------------------------------------------------------------------
[12:29:17.875] INFO: Expecting 208000 events.
[12:29:33.560] INFO: 208000 events read in total (15158ms).
[12:29:33.572] INFO: Test took 16305ms.
[12:29:34.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:34.378] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[12:29:34.378] INFO: number of red-efficiency pixels: 572 226 526 1066 1300 1477 1131 776 605 948 894 805 825 306 238 95
[12:29:34.378] INFO: number of X-ray hits detected: 218264 143262 212988 354901 362459 378905 374610 256592 231949 310593 302029 271125 282975 163704 63371 72441
[12:29:34.378] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:29:34.378] INFO: number of Vcal hits detected: 207230 207753 207339 206637 206289 205960 206518 206952 207297 206862 206919 207045 207038 207649 207747 207900
[12:29:34.378] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.4 99.3 99.1 99.4 99.6 99.7 99.5 99.5 99.6 99.6 99.8 99.9 100.0
[12:29:34.378] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.7 99.3 99.2 99.0 99.3 99.5 99.7 99.5 99.5 99.5 99.5 99.8 99.9 100.0
[12:29:34.378] INFO: X-ray hit rate [MHz/cm2]: 64.0 42.0 62.4 104.0 106.2 111.1 109.8 75.2 68.0 91.0 88.5 79.5 82.9 48.0 18.6 21.2
[12:29:34.378] INFO: PixTestHighRate::doXPixelAlive() done
[12:29:34.428] INFO: PixTest:: pg_setup set to default.
[12:29:34.444] INFO: enter test to run
[12:29:39.551] INFO: test: exit no parameter change
[12:29:39.867] QUIET: Connection to board 33 closed.
[12:29:39.868] INFO: pXar: this is the end, my friend