[13:37:41.225] INFO: *** Welcome to pxar ***
[13:37:41.225] INFO: *** Today: 2016/09/02
[13:37:41.254] INFO: *** Version: v1.9.0-818-g96727
[13:37:41.254] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//dacParameters35_C15.dat
[13:37:41.286] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:37:41.287] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[13:37:41.294] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[13:37:41.374] INFO: clk: 4
[13:37:41.374] INFO: ctr: 4
[13:37:41.374] INFO: sda: 19
[13:37:41.374] INFO: tin: 9
[13:37:41.374] INFO: level: 15
[13:37:41.375] INFO: triggerdelay: 0
[13:37:41.375] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:37:41.375] INFO: Log level: INFO
[13:37:41.392] QUIET: Connection to board DTB_WREKRL opened.
[13:37:41.396] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[13:37:41.399] INFO: RPC call hashes of host and DTB match: 398089610
[13:37:42.926] INFO: DUT info:
[13:37:42.926] INFO: The DUT currently contains the following objects:
[13:37:42.926] INFO: 2 TBM Cores tbm08c (2 ON)
[13:37:42.926] INFO: TBM Core alpha (0): 7 registers set
[13:37:42.927] INFO: TBM Core beta (1): 7 registers set
[13:37:42.927] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:37:42.927] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:42.927] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:43.331] INFO: enter 'restricted' command line mode
[13:37:43.331] INFO: enter test to run
[13:38:03.088] INFO: test: PixelAlive no parameter change
[13:38:03.088] INFO: running: pixelalive
[13:38:03.122] INFO: ----------------------------------------------------------------------
[13:38:03.122] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:38:03.122] INFO: ----------------------------------------------------------------------
[13:38:03.463] INFO: Expecting 41600 events.
[13:38:07.804] INFO: 41600 events read in total (3623ms).
[13:38:07.972] INFO: Test took 4824ms.
[13:38:07.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:08.245] INFO: PixTestAlive::aliveTest() done
[13:38:08.245] INFO: number of dead pixels (per ROC): 1 0 0 0 161 0 0 0 0 0 0 0 0 0 0 0
[13:38:08.277] INFO: enter test to run
[13:38:51.192] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:38:51.192] INFO: running: highrate
[13:38:51.214] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:38:51.430] INFO: ----------------------------------------------------------------------
[13:38:51.430] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:38:51.430] INFO: ----------------------------------------------------------------------
[13:38:51.430] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:38:51.430] INFO: edge/corner pixel THR is adjusted
[13:38:51.430] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:38:52.390] INFO: Collecting data for 5 seconds...
[13:38:57.406] INFO: Done with hot pixel readout
[13:39:08.970] INFO: PixTest:: pg_setup set to default.
[13:39:08.971] INFO: 6 hot pixels found in step 0
[13:39:09.958] INFO: Collecting data for 5 seconds...
[13:39:14.974] INFO: Done with hot pixel readout
[13:39:26.487] INFO: PixTest:: pg_setup set to default.
[13:39:26.487] INFO: 8 hot pixels found in step 1
[13:39:27.478] INFO: Collecting data for 5 seconds...
[13:39:32.494] INFO: Done with hot pixel readout
[13:39:44.078] INFO: PixTest:: pg_setup set to default.
[13:39:44.079] INFO: 7 hot pixels found in step 2
[13:39:45.069] INFO: Collecting data for 5 seconds...
[13:39:50.085] INFO: Done with hot pixel readout
[13:40:01.598] INFO: PixTest:: pg_setup set to default.
[13:40:01.599] INFO: 4 hot pixels found in step 3
[13:40:02.590] INFO: Collecting data for 5 seconds...
[13:40:07.607] INFO: Done with hot pixel readout
[13:40:19.132] INFO: PixTest:: pg_setup set to default.
[13:40:19.132] INFO: 5 hot pixels found in step 4
[13:40:20.123] INFO: Collecting data for 5 seconds...
[13:40:25.140] INFO: Done with hot pixel readout
[13:40:36.686] INFO: PixTest:: pg_setup set to default.
[13:40:36.687] INFO: 4 hot pixels found in step 5
[13:40:37.679] INFO: Collecting data for 5 seconds...
[13:40:42.696] INFO: Done with hot pixel readout
[13:40:54.253] INFO: PixTest:: pg_setup set to default.
[13:40:54.254] INFO: 2 hot pixels found in step 6
[13:40:55.244] INFO: Collecting data for 5 seconds...
[13:41:00.260] INFO: Done with hot pixel readout
[13:41:11.795] INFO: PixTest:: pg_setup set to default.
[13:41:11.796] INFO: 6 hot pixels found in step 7
[13:41:12.785] INFO: Collecting data for 5 seconds...
[13:41:17.802] INFO: Done with hot pixel readout
[13:41:29.307] INFO: PixTest:: pg_setup set to default.
[13:41:29.308] INFO: 2 hot pixels found in step 8
[13:41:30.299] INFO: Collecting data for 5 seconds...
[13:41:35.315] INFO: Done with hot pixel readout
[13:41:46.814] INFO: PixTest:: pg_setup set to default.
[13:41:46.815] INFO: 1 hot pixels found in step 9
[13:41:47.805] INFO: Collecting data for 5 seconds...
[13:41:52.821] INFO: Done with hot pixel readout
[13:42:04.336] INFO: PixTest:: pg_setup set to default.
[13:42:04.336] INFO: 5 hot pixels found in step 10
[13:42:05.328] INFO: Collecting data for 5 seconds...
[13:42:10.344] INFO: Done with hot pixel readout
[13:42:21.897] INFO: PixTest:: pg_setup set to default.
[13:42:21.898] INFO: 0 hot pixels found in step 11
[13:42:21.932] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:42:21.936] INFO: PixTest::trimHotPixels() done
[13:42:21.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat
[13:42:21.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C1.dat
[13:42:21.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C2.dat
[13:42:21.954] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C3.dat
[13:42:21.959] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C4.dat
[13:42:21.965] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C5.dat
[13:42:21.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C6.dat
[13:42:21.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C7.dat
[13:42:21.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C8.dat
[13:42:21.985] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C9.dat
[13:42:21.991] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C10.dat
[13:42:21.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C11.dat
[13:42:21.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C12.dat
[13:42:22.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C13.dat
[13:42:22.012] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C14.dat
[13:42:22.017] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[13:42:22.022] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[13:42:22.032] INFO: enter test to run
[13:42:45.743] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:42:45.743] INFO: running: highrate
[13:42:45.747] INFO: ----------------------------------------------------------------------
[13:42:45.747] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:42:45.747] INFO: ----------------------------------------------------------------------
[13:42:45.747] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:42:45.747] INFO: edge/corner pixel THR is adjusted
[13:42:45.747] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:42:46.705] INFO: Collecting data for 1 seconds...
[13:42:47.709] INFO: Done with hot pixel readout
[13:42:51.524] INFO: PixTest:: pg_setup set to default.
[13:42:51.525] INFO: 0 hot pixels found in step 0
[13:42:51.531] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:42:51.627] INFO: PixTest::trimHotPixels() done
[13:42:51.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat
[13:42:51.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C1.dat
[13:42:51.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C2.dat
[13:42:51.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C3.dat
[13:42:51.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C4.dat
[13:42:51.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C5.dat
[13:42:51.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C6.dat
[13:42:51.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C7.dat
[13:42:51.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C8.dat
[13:42:51.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C9.dat
[13:42:51.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C10.dat
[13:42:51.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C11.dat
[13:42:51.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C12.dat
[13:42:51.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C13.dat
[13:42:51.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C14.dat
[13:42:51.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[13:42:51.717] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-22_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[13:42:51.727] INFO: enter test to run
[13:43:09.102] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:43:09.102] INFO: running: xray
[13:43:09.104] INFO: ----------------------------------------------------------------------
[13:43:09.104] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:43:09.104] INFO: ----------------------------------------------------------------------
[13:43:10.067] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:43:21.647] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:43:51.022] INFO: Resuming triggers.
[13:44:02.609] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:44:32.102] INFO: Resuming triggers.
[13:44:43.687] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:45:13.633] INFO: Resuming triggers.
[13:45:25.226] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:45:54.699] INFO: Resuming triggers.
[13:46:06.287] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:46:35.743] INFO: Resuming triggers.
[13:46:47.328] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:47:16.619] INFO: Resuming triggers.
[13:47:28.210] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:47:58.404] INFO: Resuming triggers.
[13:48:09.994] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:48:40.293] INFO: Resuming triggers.
[13:48:47.950] INFO: data taking finished, elapsed time: 100 seconds.
[13:49:08.013] INFO: PixTest:: pg_setup set to default.
[13:49:08.016] INFO: PixTestXray::doPhRun() done
[13:49:08.192] INFO: enter test to run
[13:49:36.572] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:49:36.572] INFO: running: xray
[13:49:36.573] INFO: ----------------------------------------------------------------------
[13:49:36.573] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:49:36.573] INFO: ----------------------------------------------------------------------
[13:49:37.541] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:49:44.453] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:50:14.738] INFO: Resuming triggers.
[13:50:21.651] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:50:51.900] INFO: Resuming triggers.
[13:50:58.810] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:51:29.069] INFO: Resuming triggers.
[13:51:35.980] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:52:06.187] INFO: Resuming triggers.
[13:52:13.094] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:52:43.366] INFO: Resuming triggers.
[13:52:50.275] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:53:20.463] INFO: Resuming triggers.
[13:53:27.372] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[13:53:57.708] INFO: Resuming triggers.
[13:54:04.617] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:54:34.869] INFO: Resuming triggers.
[13:54:41.776] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:55:11.974] INFO: Resuming triggers.
[13:55:18.882] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:55:49.097] INFO: Resuming triggers.
[13:55:56.006] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:56:26.276] INFO: Resuming triggers.
[13:56:33.188] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:57:03.471] INFO: Resuming triggers.
[13:57:10.382] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:57:41.400] INFO: Resuming triggers.
[13:57:48.308] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:58:18.000] INFO: Resuming triggers.
[13:58:22.595] INFO: data taking finished, elapsed time: 100 seconds.
[13:58:38.981] INFO: PixTest:: pg_setup set to default.
[13:58:38.984] INFO: PixTestXray::doPhRun() done
[13:58:39.140] INFO: enter test to run
[13:59:57.168] INFO: test: HighRate no parameter change
[13:59:57.168] INFO: running: highrate
[13:59:57.169] INFO: ----------------------------------------------------------------------
[13:59:57.169] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:59:57.169] INFO: ----------------------------------------------------------------------
[13:59:57.309] INFO: Expecting 768 events.
[13:59:58.443] INFO: 768 events read in total (418ms).
[13:59:58.443] INFO: Test took 1268ms.
[13:59:59.246] INFO: Expecting 41600 events.
[14:00:02.388] INFO: 41600 events read in total (2615ms).
[14:00:02.388] INFO: Test took 3937ms.
[14:00:02.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:03.150] INFO: Expecting 41600 events.
[14:00:06.468] INFO: 41600 events read in total (2791ms).
[14:00:06.469] INFO: Test took 4032ms.
[14:00:06.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:07.218] INFO: Expecting 41600 events.
[14:00:10.527] INFO: 41600 events read in total (2782ms).
[14:00:10.528] INFO: Test took 4010ms.
[14:00:10.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:11.282] INFO: Expecting 41600 events.
[14:00:14.540] INFO: 41600 events read in total (2731ms).
[14:00:14.541] INFO: Test took 3962ms.
[14:00:14.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:15.295] INFO: Expecting 41600 events.
[14:00:18.531] INFO: 41600 events read in total (2709ms).
[14:00:18.532] INFO: Test took 3943ms.
[14:00:18.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:19.292] INFO: Expecting 41600 events.
[14:00:22.498] INFO: 41600 events read in total (2679ms).
[14:00:22.499] INFO: Test took 3919ms.
[14:00:22.532] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:23.255] INFO: Expecting 41600 events.
[14:00:26.496] INFO: 41600 events read in total (2714ms).
[14:00:26.497] INFO: Test took 3948ms.
[14:00:26.530] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:27.255] INFO: Expecting 41600 events.
[14:00:30.694] INFO: 41600 events read in total (2912ms).
[14:00:30.694] INFO: Test took 4147ms.
[14:00:30.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:31.451] INFO: Expecting 41600 events.
[14:00:34.748] INFO: 41600 events read in total (2770ms).
[14:00:34.749] INFO: Test took 4005ms.
[14:00:34.784] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:35.491] INFO: Expecting 41600 events.
[14:00:38.711] INFO: 41600 events read in total (2693ms).
[14:00:38.712] INFO: Test took 3911ms.
[14:00:38.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:39.467] INFO: Expecting 41600 events.
[14:00:42.777] INFO: 41600 events read in total (2783ms).
[14:00:42.778] INFO: Test took 4015ms.
[14:00:42.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:43.535] INFO: Expecting 41600 events.
[14:00:46.752] INFO: 41600 events read in total (2690ms).
[14:00:46.753] INFO: Test took 3925ms.
[14:00:46.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:47.512] INFO: Expecting 41600 events.
[14:00:50.719] INFO: 41600 events read in total (2680ms).
[14:00:50.720] INFO: Test took 3917ms.
[14:00:50.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:51.472] INFO: Expecting 41600 events.
[14:00:54.758] INFO: 41600 events read in total (2760ms).
[14:00:54.759] INFO: Test took 3990ms.
[14:00:54.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:55.500] INFO: Expecting 41600 events.
[14:00:58.801] INFO: 41600 events read in total (2774ms).
[14:00:58.802] INFO: Test took 3993ms.
[14:00:58.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:59.561] INFO: Expecting 41600 events.
[14:01:02.856] INFO: 41600 events read in total (2768ms).
[14:01:02.857] INFO: Test took 4006ms.
[14:01:02.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:03.616] INFO: Expecting 41600 events.
[14:01:06.872] INFO: 41600 events read in total (2729ms).
[14:01:06.873] INFO: Test took 3965ms.
[14:01:06.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:07.626] INFO: Expecting 41600 events.
[14:01:10.922] INFO: 41600 events read in total (2769ms).
[14:01:10.923] INFO: Test took 4001ms.
[14:01:10.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:11.684] INFO: Expecting 41600 events.
[14:01:14.890] INFO: 41600 events read in total (2679ms).
[14:01:14.891] INFO: Test took 3919ms.
[14:01:14.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:15.648] INFO: Expecting 41600 events.
[14:01:18.669] INFO: 41600 events read in total (2494ms).
[14:01:18.670] INFO: Test took 3729ms.
[14:01:18.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:19.070] INFO: enter test to run
[14:02:07.703] INFO: test: HighRate no parameter change
[14:02:07.703] INFO: running: highrate
[14:02:07.718] INFO: ----------------------------------------------------------------------
[14:02:07.718] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:02:07.718] INFO: ----------------------------------------------------------------------
[14:02:08.332] INFO: Expecting 208000 events.
[14:02:20.137] INFO: 208000 events read in total (11278ms).
[14:02:20.140] INFO: Test took 12411ms.
[14:02:20.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:20.518] INFO: number of dead pixels (per ROC): 1 0 0 0 137 0 0 0 0 0 0 0 0 0 0 0
[14:02:20.518] INFO: number of red-efficiency pixels: 70 44 75 110 275 137 146 87 102 125 103 81 84 54 17 18
[14:02:20.518] INFO: number of X-ray hits detected: 57692 37333 61361 97448 104087 107195 105477 75182 72247 93166 89702 76029 78691 47215 18983 22733
[14:02:20.518] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:02:20.518] INFO: number of Vcal hits detected: 207881 207955 207922 207887 199859 207860 207850 207912 207896 207875 207894 207917 207916 207945 207983 207982
[14:02:20.518] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.4 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:02:20.518] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 96.1 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:02:20.518] INFO: X-ray hit rate [MHz/cm2]: 16.9 10.9 18.0 28.6 30.5 31.4 30.9 22.0 21.2 27.3 26.3 22.3 23.1 13.8 5.6 6.7
[14:02:20.518] INFO: PixTestHighRate::doXPixelAlive() done
[14:02:20.567] INFO: PixTest:: pg_setup set to default.
[14:02:20.583] INFO: enter test to run
[14:02:53.494] INFO: test: HighRate no parameter change
[14:02:53.495] INFO: running: highrate
[14:02:53.496] INFO: ----------------------------------------------------------------------
[14:02:53.496] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:02:53.496] INFO: ----------------------------------------------------------------------
[14:02:54.115] INFO: Expecting 208000 events.
[14:03:07.497] INFO: 208000 events read in total (12856ms).
[14:03:07.502] INFO: Test took 13995ms.
[14:03:07.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:08.076] INFO: number of dead pixels (per ROC): 1 0 0 0 66 0 0 0 0 0 0 0 0 0 0 0
[14:03:08.077] INFO: number of red-efficiency pixels: 156 135 263 321 500 466 505 218 275 414 335 305 286 191 50 50
[14:03:08.077] INFO: number of X-ray hits detected: 121592 78682 129469 204707 215719 225135 220866 158130 151386 196155 188754 161341 165347 99280 40500 47839
[14:03:08.077] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:03:08.077] INFO: number of Vcal hits detected: 207789 207859 207720 207653 199719 207482 207440 207772 207715 207550 207639 207682 207694 207796 207948 207950
[14:03:08.077] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 97.5 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:03:08.077] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 96.0 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:03:08.077] INFO: X-ray hit rate [MHz/cm2]: 35.6 23.1 37.9 60.0 63.2 66.0 64.7 46.3 44.4 57.5 55.3 47.3 48.5 29.1 11.9 14.0
[14:03:08.077] INFO: PixTestHighRate::doXPixelAlive() done
[14:03:08.128] INFO: PixTest:: pg_setup set to default.
[14:03:08.147] INFO: enter test to run
[14:03:58.462] INFO: test: HighRate no parameter change
[14:03:58.462] INFO: running: highrate
[14:03:58.463] INFO: ----------------------------------------------------------------------
[14:03:58.463] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:03:58.463] INFO: ----------------------------------------------------------------------
[14:03:59.083] INFO: Expecting 208000 events.
[14:04:14.334] INFO: 208000 events read in total (14724ms).
[14:04:14.340] INFO: Test took 15867ms.
[14:04:14.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:15.102] INFO: number of dead pixels (per ROC): 1 0 0 0 41 0 0 0 0 0 0 0 0 0 0 0
[14:04:15.102] INFO: number of red-efficiency pixels: 321 224 617 757 1020 1229 1217 523 567 970 790 621 686 423 86 93
[14:04:15.102] INFO: number of X-ray hits detected: 184169 120183 196785 309601 324708 342256 336470 240850 232089 298370 286927 244984 251656 151602 61207 73404
[14:04:15.102] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:04:15.102] INFO: number of Vcal hits detected: 207604 207765 207215 207110 199131 206355 206436 207398 207369 206833 207064 207276 207224 207533 207910 207907
[14:04:15.102] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 96.6 99.3 99.3 99.7 99.7 99.5 99.6 99.7 99.7 99.8 100.0 100.0
[14:04:15.102] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.6 95.7 99.2 99.2 99.7 99.7 99.4 99.6 99.7 99.6 99.8 100.0 100.0
[14:04:15.102] INFO: X-ray hit rate [MHz/cm2]: 54.0 35.2 57.7 90.7 95.2 100.3 98.6 70.6 68.0 87.5 84.1 71.8 73.8 44.4 17.9 21.5
[14:04:15.102] INFO: PixTestHighRate::doXPixelAlive() done
[14:04:15.153] INFO: PixTest:: pg_setup set to default.
[14:04:15.165] INFO: enter test to run
[14:04:19.134] INFO: test: exit no parameter change
[14:04:19.446] QUIET: Connection to board 33 closed.
[14:04:19.447] INFO: pXar: this is the end, my friend