[13:52:46.089] INFO: *** Welcome to pxar ***
[13:52:46.089] INFO: *** Today: 2016/08/03
[13:52:46.111] INFO: *** Version: v1.9.0-818-g96727
[13:52:46.111] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//dacParameters35_C15.dat
[13:52:46.111] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:52:46.111] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//defaultMaskFile.dat
[13:52:46.111] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C15.dat
[13:52:46.181] INFO: clk: 4
[13:52:46.181] INFO: ctr: 4
[13:52:46.181] INFO: sda: 19
[13:52:46.181] INFO: tin: 9
[13:52:46.181] INFO: level: 15
[13:52:46.181] INFO: triggerdelay: 0
[13:52:46.181] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:52:46.181] INFO: Log level: INFO
[13:52:46.198] QUIET: Connection to board DTB_WREKRL opened.
[13:52:46.201] 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:52:46.204] INFO: RPC call hashes of host and DTB match: 398089610
[13:52:47.734] INFO: DUT info:
[13:52:47.735] INFO: The DUT currently contains the following objects:
[13:52:47.735] INFO: 2 TBM Cores tbm08c (2 ON)
[13:52:47.735] INFO: TBM Core alpha (0): 7 registers set
[13:52:47.735] INFO: TBM Core beta (1): 7 registers set
[13:52:47.735] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:52:47.735] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.735] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:47.736] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:52:48.139] INFO: enter 'restricted' command line mode
[13:52:48.139] INFO: enter test to run
[13:53:31.559] INFO: test: PixelAlive no parameter change
[13:53:31.559] INFO: running: pixelalive
[13:53:31.569] INFO: ----------------------------------------------------------------------
[13:53:31.569] 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:53:31.569] INFO: ----------------------------------------------------------------------
[13:53:31.889] INFO: Expecting 41600 events.
[13:53:36.204] INFO: 41600 events read in total (3597ms).
[13:53:36.376] INFO: Test took 4805ms.
[13:53:36.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:36.652] INFO: PixTestAlive::aliveTest() done
[13:53:36.652] INFO: number of dead pixels (per ROC): 1 7 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[13:53:36.682] INFO: enter test to run
[13:54:17.928] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:54:17.928] INFO: running: highrate
[13:54:17.953] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:54:18.169] INFO: ----------------------------------------------------------------------
[13:54:18.169] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:54:18.169] INFO: ----------------------------------------------------------------------
[13:54:18.170] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:54:18.170] INFO: edge/corner pixel THR is adjusted
[13:54:18.170] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:54:19.131] INFO: Collecting data for 5 seconds...
[13:54:24.148] INFO: Done with hot pixel readout
[13:54:35.635] INFO: PixTest:: pg_setup set to default.
[13:54:35.636] INFO: 26 hot pixels found in step 0
[13:54:36.649] INFO: Collecting data for 5 seconds...
[13:54:41.668] INFO: Done with hot pixel readout
[13:54:53.025] INFO: PixTest:: pg_setup set to default.

[13:54:53.026] INFO: 25 hot pixels found in step 1
[13:54:54.015] INFO: Collecting data for 5 seconds...
[13:54:59.032] INFO: Done with hot pixel readout
[13:55:10.415] INFO: PixTest:: pg_setup set to default.

[13:55:10.416] INFO: 26 hot pixels found in step 2
[13:55:11.406] INFO: Collecting data for 5 seconds...
[13:55:16.424] INFO: Done with hot pixel readout
[13:55:27.993] INFO: PixTest:: pg_setup set to default.
[13:55:27.994] INFO: 23 hot pixels found in step 3
[13:55:28.985] INFO: Collecting data for 5 seconds...
[13:55:33.002] INFO: Done with hot pixel readout
[13:55:45.104] INFO: PixTest:: pg_setup set to default.
[13:55:45.105] INFO: 24 hot pixels found in step 4
[13:55:46.095] INFO: Collecting data for 5 seconds...
[13:55:51.111] INFO: Done with hot pixel readout
[13:56:02.484] INFO: PixTest:: pg_setup set to default.

[13:56:02.485] INFO: 20 hot pixels found in step 5
[13:56:03.475] INFO: Collecting data for 5 seconds...
[13:56:08.492] INFO: Done with hot pixel readout
[13:56:19.769] INFO: PixTest:: pg_setup set to default.


[13:56:19.770] INFO: 20 hot pixels found in step 6
[13:56:20.764] INFO: Collecting data for 5 seconds...
[13:56:25.782] INFO: Done with hot pixel readout
[13:56:37.647] INFO: PixTest:: pg_setup set to default.


[13:56:37.648] INFO: 11 hot pixels found in step 7
[13:56:38.638] INFO: Collecting data for 5 seconds...
[13:56:43.658] INFO: Done with hot pixel readout
[13:56:55.826] INFO: PixTest:: pg_setup set to default.


[13:56:55.827] INFO: 7 hot pixels found in step 8
[13:56:56.817] INFO: Collecting data for 5 seconds...
[13:57:01.838] INFO: Done with hot pixel readout
[13:57:14.244] INFO: PixTest:: pg_setup set to default.



[13:57:14.245] INFO: 9 hot pixels found in step 9
[13:57:15.235] INFO: Collecting data for 5 seconds...
[13:57:20.255] INFO: Done with hot pixel readout
[13:57:32.281] INFO: PixTest:: pg_setup set to default.



[13:57:32.282] INFO: 9 hot pixels found in step 10
[13:57:33.271] INFO: Collecting data for 5 seconds...
[13:57:38.292] INFO: Done with hot pixel readout
[13:57:50.531] INFO: PixTest:: pg_setup set to default.




[13:57:50.532] INFO: 11 hot pixels found in step 11
[13:57:51.522] INFO: Collecting data for 5 seconds...
[13:57:56.542] INFO: Done with hot pixel readout
[13:58:08.534] INFO: PixTest:: pg_setup set to default.



[13:58:08.535] INFO: 11 hot pixels found in step 12
[13:58:09.524] INFO: Collecting data for 5 seconds...
[13:58:14.544] INFO: Done with hot pixel readout
[13:58:26.268] INFO: PixTest:: pg_setup set to default.



[13:58:26.269] INFO: 4 hot pixels found in step 13
[13:58:27.258] INFO: Collecting data for 5 seconds...
[13:58:32.277] INFO: Done with hot pixel readout
[13:58:44.239] INFO: PixTest:: pg_setup set to default.



[13:58:44.240] INFO: 5 hot pixels found in step 14
[13:58:44.273] INFO: 5 hot pixels could not be trimmed and have been masked.
[13:58:44.277] INFO: PixTest::trimHotPixels() done
[13:58:44.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C0.dat
[13:58:44.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C1.dat
[13:58:44.295] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C2.dat
[13:58:44.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C3.dat
[13:58:44.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C4.dat
[13:58:44.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C5.dat
[13:58:44.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C6.dat
[13:58:44.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C7.dat
[13:58:44.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C8.dat
[13:58:44.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C9.dat
[13:58:44.366] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C10.dat
[13:58:44.371] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C11.dat
[13:58:44.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C12.dat
[13:58:44.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C13.dat
[13:58:44.387] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C14.dat
[13:58:44.392] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C15.dat
[13:58:44.398] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//defaultMaskFile.dat
[13:58:44.415] INFO: enter test to run
[13:59:18.773] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:59:18.773] INFO: running: highrate
[13:59:18.778] INFO: ----------------------------------------------------------------------
[13:59:18.778] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:59:18.778] INFO: ----------------------------------------------------------------------
[13:59:18.778] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:59:18.778] INFO: edge/corner pixel THR is adjusted
[13:59:18.778] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:59:19.736] INFO: Collecting data for 1 seconds...
[13:59:20.740] INFO: Done with hot pixel readout
[13:59:24.871] INFO: PixTest:: pg_setup set to default.
[13:59:24.871] INFO: 0 hot pixels found in step 0
[13:59:24.877] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:59:24.963] INFO: PixTest::trimHotPixels() done
[13:59:24.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C0.dat
[13:59:24.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C1.dat
[13:59:24.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C2.dat
[13:59:24.985] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C3.dat
[13:59:24.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C4.dat
[13:59:24.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C5.dat
[13:59:24.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C6.dat
[13:59:24.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C7.dat
[13:59:25.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C8.dat
[13:59:25.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C9.dat
[13:59:25.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C10.dat
[13:59:25.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C11.dat
[13:59:25.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C12.dat
[13:59:25.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C13.dat
[13:59:25.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C14.dat
[13:59:25.048] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//trimParameters35_C15.dat
[13:59:25.053] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-38_FPIXTest-17C-FNAL-160722-1101_2016-07-22_11h01m_1469203318/000_FPIXTest_p17//defaultMaskFile.dat
[13:59:25.063] INFO: enter test to run
[14:00:25.028] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:00:25.029] INFO: running: xray
[14:00:25.030] INFO: ----------------------------------------------------------------------
[14:00:25.030] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:00:25.030] INFO: ----------------------------------------------------------------------
[14:00:25.994] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:00:37.241] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:01:06.699] INFO: Resuming triggers.
[14:01:17.946] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:01:47.100] INFO: Resuming triggers.
[14:01:58.346] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:02:27.736] INFO: Resuming triggers.
[14:02:38.981] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:03:08.334] INFO: Resuming triggers.
[14:03:19.579] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:03:48.900] INFO: Resuming triggers.
[14:04:00.144] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:04:29.588] INFO: Resuming triggers.
[14:04:40.833] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:05:10.183] INFO: Resuming triggers.
[14:05:21.426] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:05:51.026] INFO: Resuming triggers.
[14:06:01.406] INFO: data taking finished, elapsed time: 100 seconds.
[14:06:28.465] INFO: PixTest:: pg_setup set to default.
[14:06:28.468] INFO: PixTestXray::doPhRun() done
[14:06:28.647] INFO: enter test to run
[14:07:16.778] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:07:16.778] INFO: running: xray
[14:07:16.779] INFO: ----------------------------------------------------------------------
[14:07:16.779] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:07:16.779] INFO: ----------------------------------------------------------------------
[14:07:17.752] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:07:24.271] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:07:55.171] INFO: Resuming triggers.
[14:08:01.691] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:08:32.581] INFO: Resuming triggers.
[14:08:39.102] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:09:10.351] INFO: Resuming triggers.
[14:09:16.872] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[14:09:48.257] INFO: Resuming triggers.
[14:09:54.779] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:10:25.971] INFO: Resuming triggers.
[14:10:32.491] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[14:11:02.686] INFO: Resuming triggers.
[14:11:09.204] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:11:39.240] INFO: Resuming triggers.
[14:11:45.761] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:12:15.843] INFO: Resuming triggers.
[14:12:22.364] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:12:52.437] INFO: Resuming triggers.
[14:12:58.956] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:13:29.118] INFO: Resuming triggers.
[14:13:35.640] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:14:05.838] INFO: Resuming triggers.
[14:14:12.353] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:14:42.608] INFO: Resuming triggers.
[14:14:49.130] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:15:19.301] INFO: Resuming triggers.
[14:15:25.818] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:15:56.062] INFO: Resuming triggers.
[14:16:02.583] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:16:32.794] INFO: Resuming triggers.
[14:16:35.346] INFO: data taking finished, elapsed time: 100 seconds.
[14:16:47.399] INFO: PixTest:: pg_setup set to default.
[14:16:47.402] INFO: PixTestXray::doPhRun() done
[14:16:47.548] INFO: enter test to run
[14:17:34.638] INFO: test: HighRate no parameter change
[14:17:34.638] INFO: running: highrate
[14:17:34.639] INFO: ----------------------------------------------------------------------
[14:17:34.639] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:17:34.639] INFO: ----------------------------------------------------------------------
[14:17:34.779] INFO: Expecting 768 events.
[14:17:35.913] INFO: 768 events read in total (418ms).
[14:17:35.913] INFO: Test took 1268ms.
[14:17:36.716] INFO: Expecting 41600 events.
[14:17:39.738] INFO: 41600 events read in total (2495ms).
[14:17:39.739] INFO: Test took 3817ms.
[14:17:39.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:40.498] INFO: Expecting 41600 events.
[14:17:43.693] INFO: 41600 events read in total (2669ms).
[14:17:43.694] INFO: Test took 3903ms.
[14:17:43.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:44.451] INFO: Expecting 41600 events.
[14:17:47.688] INFO: 41600 events read in total (2710ms).
[14:17:47.689] INFO: Test took 3941ms.
[14:17:47.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:48.444] INFO: Expecting 41600 events.
[14:17:51.695] INFO: 41600 events read in total (2724ms).
[14:17:51.696] INFO: Test took 3953ms.
[14:17:51.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:52.450] INFO: Expecting 41600 events.
[14:17:55.647] INFO: 41600 events read in total (2670ms).
[14:17:55.648] INFO: Test took 3899ms.
[14:17:55.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:56.408] INFO: Expecting 41600 events.
[14:17:59.665] INFO: 41600 events read in total (2730ms).
[14:17:59.666] INFO: Test took 3963ms.
[14:17:59.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:00.420] INFO: Expecting 41600 events.
[14:18:03.663] INFO: 41600 events read in total (2716ms).
[14:18:03.664] INFO: Test took 3943ms.
[14:18:03.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:04.422] INFO: Expecting 41600 events.
[14:18:07.668] INFO: 41600 events read in total (2719ms).
[14:18:07.669] INFO: Test took 3951ms.
[14:18:07.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:08.424] INFO: Expecting 41600 events.
[14:18:11.676] INFO: 41600 events read in total (2725ms).
[14:18:11.677] INFO: Test took 3953ms.
[14:18:11.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:12.434] INFO: Expecting 41600 events.
[14:18:15.695] INFO: 41600 events read in total (2734ms).
[14:18:15.696] INFO: Test took 3965ms.
[14:18:15.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:16.451] INFO: Expecting 41600 events.
[14:18:19.719] INFO: 41600 events read in total (2741ms).
[14:18:19.720] INFO: Test took 3969ms.
[14:18:19.756] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:20.480] INFO: Expecting 41600 events.
[14:18:23.725] INFO: 41600 events read in total (2718ms).
[14:18:23.726] INFO: Test took 3951ms.
[14:18:23.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:24.483] INFO: Expecting 41600 events.
[14:18:27.722] INFO: 41600 events read in total (2712ms).
[14:18:27.723] INFO: Test took 3943ms.
[14:18:27.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:28.482] INFO: Expecting 41600 events.
[14:18:31.752] INFO: 41600 events read in total (2743ms).
[14:18:31.753] INFO: Test took 3976ms.
[14:18:31.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:32.506] INFO: Expecting 41600 events.
[14:18:35.813] INFO: 41600 events read in total (2780ms).
[14:18:35.814] INFO: Test took 4006ms.
[14:18:35.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:36.571] INFO: Expecting 41600 events.
[14:18:39.845] INFO: 41600 events read in total (2748ms).
[14:18:39.845] INFO: Test took 3978ms.
[14:18:39.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:40.603] INFO: Expecting 41600 events.
[14:18:43.936] INFO: 41600 events read in total (2806ms).
[14:18:43.937] INFO: Test took 4034ms.
[14:18:43.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:44.690] INFO: Expecting 41600 events.
[14:18:47.933] INFO: 41600 events read in total (2716ms).
[14:18:47.934] INFO: Test took 3943ms.
[14:18:47.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:48.692] INFO: Expecting 41600 events.
[14:18:51.904] INFO: 41600 events read in total (2685ms).
[14:18:51.905] INFO: Test took 3917ms.
[14:18:51.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:52.652] INFO: Expecting 41600 events.
[14:18:55.764] INFO: 41600 events read in total (2585ms).
[14:18:55.765] INFO: Test took 3788ms.
[14:18:55.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:56.162] INFO: enter test to run
[14:19:05.469] INFO: test: HighRate no parameter change
[14:19:05.469] INFO: running: highrate
[14:19:05.470] INFO: ----------------------------------------------------------------------
[14:19:05.470] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:19:05.471] INFO: ----------------------------------------------------------------------
[14:19:06.087] INFO: Expecting 208000 events.
[14:19:18.073] INFO: 208000 events read in total (11459ms).
[14:19:18.076] INFO: Test took 12599ms.
[14:19:18.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:18.485] INFO: number of dead pixels (per ROC): 1 7 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[14:19:18.485] INFO: number of red-efficiency pixels: 102 60 63 123 127 114 134 82 81 170 157 112 123 75 32 37
[14:19:18.485] INFO: number of X-ray hits detected: 76420 43856 59276 99405 105607 103090 109918 73263 78504 118800 115709 104314 108876 61170 24063 24835
[14:19:18.485] 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:19:18.485] INFO: number of Vcal hits detected: 207846 207597 207937 207875 207868 207884 207863 207916 207869 207828 207841 207886 207875 207923 207968 207963
[14:19:18.485] 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 100.0 100.0
[14:19:18.485] INFO: Vcal hit overall efficiency (%): 99.9 99.8 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:19:18.485] INFO: X-ray hit rate [MHz/cm2]: 22.4 12.9 17.4 29.1 31.0 30.2 32.2 21.5 23.0 34.8 33.9 30.6 31.9 17.9 7.1 7.3
[14:19:18.485] INFO: PixTestHighRate::doXPixelAlive() done
[14:19:18.530] INFO: PixTest:: pg_setup set to default.
[14:19:18.543] INFO: enter test to run
[14:19:53.517] INFO: test: HighRate no parameter change
[14:19:53.517] INFO: running: highrate
[14:19:53.518] INFO: ----------------------------------------------------------------------
[14:19:53.518] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:19:53.518] INFO: ----------------------------------------------------------------------
[14:19:54.140] INFO: Expecting 208000 events.
[14:20:08.224] INFO: 208000 events read in total (13558ms).
[14:20:08.229] INFO: Test took 14702ms.
[14:20:08.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:08.856] INFO: number of dead pixels (per ROC): 1 7 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[14:20:08.856] INFO: number of red-efficiency pixels: 320 135 173 321 410 342 533 232 256 598 458 376 413 254 56 64
[14:20:08.856] INFO: number of X-ray hits detected: 157350 90616 123479 206366 220269 213398 228397 151626 163528 246844 238847 216631 226438 127775 50035 52468
[14:20:08.856] 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:20:08.856] INFO: number of Vcal hits detected: 207592 207512 207816 207656 207559 207636 207409 207753 207676 207326 207502 207590 207566 207729 207943 207935
[14:20:08.856] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.9 99.9 99.8 99.8 99.7 99.9 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:20:08.856] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.9 99.8 99.8 99.8 99.7 99.9 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:20:08.856] INFO: X-ray hit rate [MHz/cm2]: 46.1 26.6 36.2 60.5 64.6 62.5 66.9 44.4 47.9 72.4 70.0 63.5 66.4 37.5 14.7 15.4
[14:20:08.856] INFO: PixTestHighRate::doXPixelAlive() done
[14:20:08.904] INFO: PixTest:: pg_setup set to default.
[14:20:08.921] INFO: enter test to run
[14:20:43.492] INFO: test: HighRate no parameter change
[14:20:43.492] INFO: running: highrate
[14:20:43.493] INFO: ----------------------------------------------------------------------
[14:20:43.493] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:20:43.493] INFO: ----------------------------------------------------------------------
[14:20:44.109] INFO: Expecting 208000 events.
[14:21:00.176] INFO: 208000 events read in total (15540ms).
[14:21:00.183] INFO: Test took 16683ms.
[14:21:00.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:01.024] INFO: number of dead pixels (per ROC): 1 7 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:21:01.024] INFO: number of red-efficiency pixels: 665 317 415 763 973 812 1208 494 525 1423 1064 804 907 563 127 108
[14:21:01.024] INFO: number of X-ray hits detected: 235594 135927 185148 310206 329293 319732 340936 227835 245102 369495 359898 325302 340573 192698 75319 78519
[14:21:01.025] 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:21:01.025] INFO: number of Vcal hits detected: 207031 207301 207519 207119 206803 207008 206372 207414 207345 206090 206663 207023 206930 207283 207870 207889
[14:21:01.025] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.8 99.6 99.5 99.6 99.3 99.8 99.7 99.2 99.4 99.6 99.5 99.7 99.9 99.9
[14:21:01.025] INFO: Vcal hit overall efficiency (%): 99.5 99.7 99.8 99.6 99.4 99.5 99.2 99.7 99.7 99.1 99.4 99.5 99.5 99.7 99.9 99.9
[14:21:01.025] INFO: X-ray hit rate [MHz/cm2]: 69.1 39.8 54.3 90.9 96.5 93.7 99.9 66.8 71.8 108.3 105.5 95.3 99.8 56.5 22.1 23.0
[14:21:01.025] INFO: PixTestHighRate::doXPixelAlive() done
[14:21:01.070] INFO: PixTest:: pg_setup set to default.
[14:21:01.087] INFO: enter test to run
[14:21:19.604] INFO: test: exit no parameter change
[14:21:19.858] QUIET: Connection to board 33 closed.
[14:21:19.860] INFO: pXar: this is the end, my friend