[11:21:23.491] INFO: *** Welcome to pxar ***
[11:21:23.491] INFO: *** Today: 2016/07/14
[11:21:23.525] INFO: *** Version: v1.9.0-814-g7497
[11:21:23.525] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//dacParameters35_C15.dat
[11:21:23.567] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:21:23.567] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//defaultMaskFile.dat
[11:21:23.567] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C15.dat
[11:21:23.688] INFO: clk: 4
[11:21:23.688] INFO: ctr: 4
[11:21:23.688] INFO: sda: 19
[11:21:23.688] INFO: tin: 9
[11:21:23.688] INFO: level: 15
[11:21:23.688] INFO: triggerdelay: 0
[11:21:23.688] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:21:23.688] INFO: Log level: INFO
[11:21:23.706] QUIET: Connection to board DTB_WREKRL opened.
[11:21:23.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:
------------------------------------------------------
[11:21:23.712] INFO: RPC call hashes of host and DTB match: 398089610
[11:21:25.242] INFO: DUT info:
[11:21:25.242] INFO: The DUT currently contains the following objects:
[11:21:25.242] INFO: 2 TBM Cores tbm08c (2 ON)
[11:21:25.242] INFO: TBM Core alpha (0): 7 registers set
[11:21:25.242] INFO: TBM Core beta (1): 7 registers set
[11:21:25.242] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:21:25.242] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.242] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.242] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.242] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.243] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:21:25.673] INFO: enter 'restricted' command line mode
[11:21:25.673] INFO: enter test to run
[11:21:39.458] INFO: test: PixelAlive no parameter change
[11:21:39.458] INFO: running: pixelalive
[11:21:39.467] INFO: ----------------------------------------------------------------------
[11:21:39.467] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:21:39.467] INFO: ----------------------------------------------------------------------
[11:21:39.786] INFO: Expecting 41600 events.
[11:21:44.136] INFO: 41600 events read in total (3631ms).
[11:21:44.301] INFO: Test took 4832ms.
[11:21:44.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:44.573] INFO: PixTestAlive::aliveTest() done
[11:21:44.573] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 1 0 3 2 0
[11:21:44.605] INFO: enter test to run
[11:22:27.042] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:22:27.042] INFO: running: highrate
[11:22:27.042] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:22:27.318] INFO: ----------------------------------------------------------------------
[11:22:27.319] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:22:27.319] INFO: ----------------------------------------------------------------------
[11:22:27.319] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:22:27.319] INFO: edge/corner pixel THR is adjusted
[11:22:27.319] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:22:28.277] INFO: Collecting data for 5 seconds...
[11:22:33.292] INFO: Done with hot pixel readout
[11:22:44.933] INFO: PixTest:: pg_setup set to default.
[11:22:44.934] INFO: 23 hot pixels found in step 0
[11:22:45.927] INFO: Collecting data for 5 seconds...
[11:22:50.943] INFO: Done with hot pixel readout
[11:23:02.301] INFO: PixTest:: pg_setup set to default.
[11:23:02.302] INFO: 23 hot pixels found in step 1
[11:23:03.300] INFO: Collecting data for 5 seconds...
[11:23:08.316] INFO: Done with hot pixel readout
[11:23:19.896] INFO: PixTest:: pg_setup set to default.
[11:23:19.897] INFO: 26 hot pixels found in step 2
[11:23:20.893] INFO: Collecting data for 5 seconds...
[11:23:25.909] INFO: Done with hot pixel readout
[11:23:37.725] INFO: PixTest:: pg_setup set to default.
[11:23:37.726] INFO: 26 hot pixels found in step 3
[11:23:38.721] INFO: Collecting data for 5 seconds...
[11:23:43.738] INFO: Done with hot pixel readout
[11:23:55.043] INFO: PixTest:: pg_setup set to default.

[11:23:55.044] INFO: 18 hot pixels found in step 4
[11:23:56.038] INFO: Collecting data for 5 seconds...
[11:24:01.053] INFO: Done with hot pixel readout
[11:24:12.498] INFO: PixTest:: pg_setup set to default.



[11:24:12.499] INFO: 16 hot pixels found in step 5
[11:24:13.494] INFO: Collecting data for 5 seconds...
[11:24:18.510] INFO: Done with hot pixel readout
[11:24:30.336] INFO: PixTest:: pg_setup set to default.



[11:24:30.337] INFO: 22 hot pixels found in step 6
[11:24:31.332] INFO: Collecting data for 5 seconds...
[11:24:36.349] INFO: Done with hot pixel readout
[11:24:47.778] INFO: PixTest:: pg_setup set to default.




[11:24:47.779] INFO: 15 hot pixels found in step 7
[11:24:48.773] INFO: Collecting data for 5 seconds...
[11:24:53.789] INFO: Done with hot pixel readout
[11:25:05.090] INFO: PixTest:: pg_setup set to default.






[11:25:05.091] INFO: 16 hot pixels found in step 8
[11:25:06.087] INFO: Collecting data for 5 seconds...
[11:25:11.103] INFO: Done with hot pixel readout
[11:25:22.375] INFO: PixTest:: pg_setup set to default.





[11:25:22.376] INFO: 18 hot pixels found in step 9
[11:25:23.373] INFO: Collecting data for 5 seconds...
[11:25:28.389] INFO: Done with hot pixel readout
[11:25:39.739] INFO: PixTest:: pg_setup set to default.





[11:25:39.740] INFO: 16 hot pixels found in step 10
[11:25:40.735] INFO: Collecting data for 5 seconds...
[11:25:45.751] INFO: Done with hot pixel readout
[11:25:57.275] INFO: PixTest:: pg_setup set to default.





[11:25:57.276] INFO: 10 hot pixels found in step 11
[11:25:58.271] INFO: Collecting data for 5 seconds...
[11:26:03.288] INFO: Done with hot pixel readout
[11:26:14.941] INFO: PixTest:: pg_setup set to default.



[11:26:14.942] INFO: 8 hot pixels found in step 12
[11:26:15.937] INFO: Collecting data for 5 seconds...
[11:26:20.954] INFO: Done with hot pixel readout
[11:26:32.468] INFO: PixTest:: pg_setup set to default.




[11:26:32.470] INFO: 12 hot pixels found in step 13
[11:26:33.465] INFO: Collecting data for 5 seconds...
[11:26:38.481] INFO: Done with hot pixel readout
[11:26:49.939] INFO: PixTest:: pg_setup set to default.



[11:26:49.940] INFO: 7 hot pixels found in step 14
[11:26:49.980] INFO: 7 hot pixels could not be trimmed and have been masked.
[11:26:49.984] INFO: PixTest::trimHotPixels() done
[11:26:49.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C0.dat
[11:26:49.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C1.dat
[11:26:49.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C2.dat
[11:26:49.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C3.dat
[11:26:50.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C4.dat
[11:26:50.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C5.dat
[11:26:50.019] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C6.dat
[11:26:50.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C7.dat
[11:26:50.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C8.dat
[11:26:50.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C9.dat
[11:26:50.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C10.dat
[11:26:50.048] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C11.dat
[11:26:50.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C12.dat
[11:26:50.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C13.dat
[11:26:50.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C14.dat
[11:26:50.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C15.dat
[11:26:50.077] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//defaultMaskFile.dat
[11:26:50.087] INFO: enter test to run
[11:27:35.608] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:27:35.608] INFO: running: highrate
[11:27:35.612] INFO: ----------------------------------------------------------------------
[11:27:35.612] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:27:35.612] INFO: ----------------------------------------------------------------------
[11:27:35.612] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:27:35.612] INFO: edge/corner pixel THR is adjusted
[11:27:35.612] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:27:36.570] INFO: Collecting data for 1 seconds...
[11:27:37.573] INFO: Done with hot pixel readout
[11:27:41.498] INFO: PixTest:: pg_setup set to default.
[11:27:41.499] INFO: 0 hot pixels found in step 0
[11:27:41.504] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:27:41.587] INFO: PixTest::trimHotPixels() done
[11:27:41.587] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C0.dat
[11:27:41.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C1.dat
[11:27:41.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C2.dat
[11:27:41.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C3.dat
[11:27:41.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C4.dat
[11:27:41.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C5.dat
[11:27:41.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C6.dat
[11:27:41.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C7.dat
[11:27:41.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C8.dat
[11:27:41.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C9.dat
[11:27:41.656] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C10.dat
[11:27:41.662] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C11.dat
[11:27:41.667] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C12.dat
[11:27:41.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C13.dat
[11:27:41.679] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C14.dat
[11:27:41.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//trimParameters35_C15.dat
[11:27:41.690] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-49_FPIXTest-17C-FNAL-160712-1223_2016-07-12_12h23m_1468344199/000_FPIXTest_p17//defaultMaskFile.dat
[11:27:41.700] INFO: enter test to run
[11:28:12.439] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:28:12.439] INFO: running: xray
[11:28:12.440] INFO: ----------------------------------------------------------------------
[11:28:12.440] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:28:12.440] INFO: ----------------------------------------------------------------------
[11:28:13.403] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:28:24.426] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[11:28:52.839] INFO: Resuming triggers.
[11:29:03.863] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:29:32.924] INFO: Resuming triggers.
[11:29:43.949] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:30:13.791] INFO: Resuming triggers.
[11:30:24.818] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:30:54.263] INFO: Resuming triggers.
[11:31:05.289] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:31:34.459] INFO: Resuming triggers.
[11:31:45.486] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[11:32:14.097] INFO: Resuming triggers.
[11:32:25.127] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[11:32:53.776] INFO: Resuming triggers.
[11:33:04.808] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[11:33:33.220] INFO: Resuming triggers.
[11:33:44.255] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[11:34:12.922] INFO: Resuming triggers.
[11:34:14.007] INFO: data taking finished, elapsed time: 100 seconds.
[11:34:17.352] INFO: PixTest:: pg_setup set to default.
[11:34:17.356] INFO: PixTestXray::doPhRun() done
[11:34:17.541] INFO: enter test to run
[11:34:51.573] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:34:51.573] INFO: running: xray
[11:34:51.574] INFO: ----------------------------------------------------------------------
[11:34:51.574] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:34:51.574] INFO: ----------------------------------------------------------------------
[11:34:52.549] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:34:58.867] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:35:28.022] INFO: Resuming triggers.
[11:35:34.339] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[11:36:02.864] INFO: Resuming triggers.
[11:36:09.180] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[11:36:38.525] INFO: Resuming triggers.
[11:36:44.842] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[11:37:15.068] INFO: Resuming triggers.
[11:37:21.385] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[11:37:50.156] INFO: Resuming triggers.
[11:37:56.471] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[11:38:26.694] INFO: Resuming triggers.
[11:38:33.007] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[11:39:03.821] INFO: Resuming triggers.
[11:39:10.136] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[11:39:40.326] INFO: Resuming triggers.
[11:39:46.643] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:40:16.274] INFO: Resuming triggers.
[11:40:22.589] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[11:40:52.782] INFO: Resuming triggers.
[11:40:59.101] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[11:41:28.344] INFO: Resuming triggers.
[11:41:34.659] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:42:04.758] INFO: Resuming triggers.
[11:42:11.076] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:42:41.710] INFO: Resuming triggers.
[11:42:48.027] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:43:18.108] INFO: Resuming triggers.
[11:43:24.424] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[11:43:54.184] INFO: Resuming triggers.
[11:43:59.775] INFO: data taking finished, elapsed time: 100 seconds.
[11:44:26.409] INFO: PixTest:: pg_setup set to default.
[11:44:26.412] INFO: PixTestXray::doPhRun() done
[11:44:26.561] INFO: enter test to run
[11:45:26.376] INFO: test: HighRate no parameter change
[11:45:26.376] INFO: running: highrate
[11:45:26.395] INFO: ----------------------------------------------------------------------
[11:45:26.396] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:45:26.396] INFO: ----------------------------------------------------------------------
[11:45:26.552] INFO: Expecting 768 events.
[11:45:27.686] INFO: 768 events read in total (419ms).
[11:45:27.686] INFO: Test took 1269ms.
[11:45:28.489] INFO: Expecting 41600 events.
[11:45:31.669] INFO: 41600 events read in total (2654ms).
[11:45:31.670] INFO: Test took 3979ms.
[11:45:31.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:32.428] INFO: Expecting 41600 events.
[11:45:35.523] INFO: 41600 events read in total (2569ms).
[11:45:35.524] INFO: Test took 3799ms.
[11:45:35.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:36.280] INFO: Expecting 41600 events.
[11:45:39.553] INFO: 41600 events read in total (2746ms).
[11:45:39.554] INFO: Test took 3974ms.
[11:45:39.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:40.307] INFO: Expecting 41600 events.
[11:45:43.541] INFO: 41600 events read in total (2707ms).
[11:45:43.542] INFO: Test took 3931ms.
[11:45:43.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:44.299] INFO: Expecting 41600 events.
[11:45:47.521] INFO: 41600 events read in total (2695ms).
[11:45:47.522] INFO: Test took 3922ms.
[11:45:47.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:48.277] INFO: Expecting 41600 events.
[11:45:51.258] INFO: 41600 events read in total (2455ms).
[11:45:51.259] INFO: Test took 3681ms.
[11:45:51.298] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:52.015] INFO: Expecting 41600 events.
[11:45:55.224] INFO: 41600 events read in total (2682ms).
[11:45:55.225] INFO: Test took 3908ms.
[11:45:55.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:55.982] INFO: Expecting 41600 events.
[11:45:59.269] INFO: 41600 events read in total (2760ms).
[11:45:59.270] INFO: Test took 3985ms.
[11:45:59.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:00.022] INFO: Expecting 41600 events.
[11:46:03.230] INFO: 41600 events read in total (2682ms).
[11:46:03.231] INFO: Test took 3905ms.
[11:46:03.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:03.985] INFO: Expecting 41600 events.
[11:46:07.175] INFO: 41600 events read in total (2664ms).
[11:46:07.176] INFO: Test took 3888ms.
[11:46:07.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:07.934] INFO: Expecting 41600 events.
[11:46:11.222] INFO: 41600 events read in total (2761ms).
[11:46:11.223] INFO: Test took 3990ms.
[11:46:11.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:11.977] INFO: Expecting 41600 events.
[11:46:15.205] INFO: 41600 events read in total (2701ms).
[11:46:15.207] INFO: Test took 3928ms.
[11:46:15.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:15.958] INFO: Expecting 41600 events.
[11:46:19.229] INFO: 41600 events read in total (2744ms).
[11:46:19.231] INFO: Test took 3967ms.
[11:46:19.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:19.988] INFO: Expecting 41600 events.
[11:46:23.198] INFO: 41600 events read in total (2683ms).
[11:46:23.199] INFO: Test took 3912ms.
[11:46:23.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:23.953] INFO: Expecting 41600 events.
[11:46:27.238] INFO: 41600 events read in total (2758ms).
[11:46:27.239] INFO: Test took 3985ms.
[11:46:27.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:27.994] INFO: Expecting 41600 events.
[11:46:31.275] INFO: 41600 events read in total (2754ms).
[11:46:31.276] INFO: Test took 3979ms.
[11:46:31.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:32.030] INFO: Expecting 41600 events.
[11:46:35.281] INFO: 41600 events read in total (2724ms).
[11:46:35.282] INFO: Test took 3949ms.
[11:46:35.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:36.034] INFO: Expecting 41600 events.
[11:46:39.262] INFO: 41600 events read in total (2701ms).
[11:46:39.263] INFO: Test took 3925ms.
[11:46:39.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:40.021] INFO: Expecting 41600 events.
[11:46:42.937] INFO: 41600 events read in total (2390ms).
[11:46:42.938] INFO: Test took 3618ms.
[11:46:42.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:43.694] INFO: Expecting 41600 events.
[11:46:46.688] INFO: 41600 events read in total (2467ms).
[11:46:46.689] INFO: Test took 3694ms.
[11:46:46.726] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:47.077] INFO: enter test to run
[11:46:58.367] INFO: test: HighRate no parameter change
[11:46:58.367] INFO: running: highrate
[11:46:58.369] INFO: ----------------------------------------------------------------------
[11:46:58.369] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:46:58.369] INFO: ----------------------------------------------------------------------
[11:46:58.985] INFO: Expecting 208000 events.
[11:47:10.245] INFO: 208000 events read in total (10733ms).
[11:47:10.249] INFO: Test took 11870ms.
[11:47:10.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:10.668] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 1 0 3 2 0
[11:47:10.668] INFO: number of red-efficiency pixels: 80 59 105 163 144 146 158 122 98 171 182 111 142 86 32 30
[11:47:10.668] INFO: number of X-ray hits detected: 67980 46483 73920 111657 122593 124427 128079 89753 89079 118319 119390 96738 100205 61977 23869 28054
[11:47:10.668] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:47:10.668] INFO: number of Vcal hits detected: 207916 207941 207892 207788 207853 207851 207792 207876 207901 207825 207808 207838 207855 207765 207869 207970
[11:47:10.668] INFO: Vcal hit fiducial 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
[11:47:10.668] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0
[11:47:10.668] INFO: X-ray hit rate [MHz/cm2]: 19.9 13.6 21.7 32.7 35.9 36.5 37.5 26.3 26.1 34.7 35.0 28.4 29.4 18.2 7.0 8.2
[11:47:10.668] INFO: PixTestHighRate::doXPixelAlive() done
[11:47:10.713] INFO: PixTest:: pg_setup set to default.
[11:47:10.724] INFO: enter test to run
[11:48:04.279] INFO: test: HighRate no parameter change
[11:48:04.279] INFO: running: highrate
[11:48:04.280] INFO: ----------------------------------------------------------------------
[11:48:04.281] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:48:04.281] INFO: ----------------------------------------------------------------------
[11:48:04.904] INFO: Expecting 208000 events.
[11:48:18.515] INFO: 208000 events read in total (13084ms).
[11:48:18.522] INFO: Test took 14232ms.
[11:48:18.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:19.173] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 1 0 3 2 0
[11:48:19.173] INFO: number of red-efficiency pixels: 259 126 264 513 493 475 523 379 279 583 585 377 448 266 57 75
[11:48:19.173] INFO: number of X-ray hits detected: 137399 94531 150251 226164 247898 250982 257956 181285 180275 240168 241880 196056 203493 125902 48829 56992
[11:48:19.173] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:48:19.173] INFO: number of Vcal hits detected: 207719 207870 207715 207373 207470 207489 207353 207579 207715 207363 207347 207553 207522 207562 207845 207923
[11:48:19.173] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.8 99.7 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[11:48:19.173] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.7 99.8 99.9 99.7 99.7 99.8 99.8 99.8 99.9 100.0
[11:48:19.173] INFO: X-ray hit rate [MHz/cm2]: 40.3 27.7 44.0 66.3 72.7 73.6 75.6 53.1 52.8 70.4 70.9 57.5 59.6 36.9 14.3 16.7
[11:48:19.173] INFO: PixTestHighRate::doXPixelAlive() done
[11:48:19.219] INFO: PixTest:: pg_setup set to default.
[11:48:19.229] INFO: enter test to run
[11:48:46.511] INFO: test: HighRate no parameter change
[11:48:46.511] INFO: running: highrate
[11:48:46.512] INFO: ----------------------------------------------------------------------
[11:48:46.512] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:48:46.512] INFO: ----------------------------------------------------------------------
[11:48:47.130] INFO: Expecting 208000 events.
[11:49:02.702] INFO: 208000 events read in total (15045ms).
[11:49:02.710] INFO: Test took 16189ms.
[11:49:03.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:03.574] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 1 0 3 2 0
[11:49:03.574] INFO: number of red-efficiency pixels: 558 315 581 1272 1190 1118 1223 835 595 1390 1475 807 996 634 121 120
[11:49:03.574] INFO: number of X-ray hits detected: 207164 142560 226846 339713 372959 378634 388532 272392 271765 360346 363879 296567 306651 189910 73510 87019
[11:49:03.574] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:49:03.574] INFO: number of Vcal hits detected: 207311 207664 207284 206296 206462 206603 206251 206926 207296 206135 206036 206963 206770 207014 207774 207877
[11:49:03.574] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.7 99.3 99.3 99.4 99.2 99.5 99.7 99.2 99.1 99.6 99.5 99.6 99.9 99.9
[11:49:03.575] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.7 99.2 99.3 99.3 99.2 99.5 99.7 99.1 99.1 99.5 99.4 99.5 99.9 99.9
[11:49:03.575] INFO: X-ray hit rate [MHz/cm2]: 60.7 41.8 66.5 99.6 109.3 111.0 113.9 79.8 79.7 105.6 106.7 86.9 89.9 55.7 21.5 25.5
[11:49:03.575] INFO: PixTestHighRate::doXPixelAlive() done
[11:49:03.624] INFO: PixTest:: pg_setup set to default.
[11:49:03.641] INFO: enter test to run
[11:49:30.222] INFO: test: exit no parameter change
[11:49:30.661] QUIET: Connection to board 33 closed.
[11:49:30.662] INFO: pXar: this is the end, my friend