[14:38:47.568] INFO: *** Welcome to pxar ***
[14:38:47.568] INFO: *** Today: 2016/07/06
[14:38:48.351] INFO: *** Version: v1.9.0-814-g7497
[14:38:48.352] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//dacParameters35_C15.dat
[14:38:48.430] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:38:48.430] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:48.430] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:48.593] INFO: clk: 4
[14:38:48.594] INFO: ctr: 4
[14:38:48.594] INFO: sda: 19
[14:38:48.594] INFO: tin: 9
[14:38:48.594] INFO: level: 15
[14:38:48.594] INFO: triggerdelay: 0
[14:38:48.594] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:38:48.594] INFO: Log level: INFO
[14:38:48.610] QUIET: Connection to board DTB_WREKRL opened.
[14:38:48.614] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[14:38:48.616] INFO: RPC call hashes of host and DTB match: 398089610
[14:38:50.148] INFO: DUT info:
[14:38:50.148] INFO: The DUT currently contains the following objects:
[14:38:50.148] INFO: 2 TBM Cores tbm08c (2 ON)
[14:38:50.161] INFO: TBM Core alpha (0): 7 registers set
[14:38:50.161] INFO: TBM Core beta (1): 7 registers set
[14:38:50.161] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:38:50.161] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.162] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:50.630] INFO: enter 'restricted' command line mode
[14:38:50.631] INFO: enter test to run
[14:38:50.631] INFO: test: y no parameter change
[14:38:50.631] INFO: running: y
[14:38:50.631] INFO: command ->y<- not known, ignored
[14:38:50.631] INFO: enter test to run
[14:39:17.853] INFO: test: PixelAlive no parameter change
[14:39:17.853] INFO: running: pixelalive
[14:39:17.862] INFO: ----------------------------------------------------------------------
[14:39:17.862] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:39:17.862] INFO: ----------------------------------------------------------------------
[14:39:18.185] INFO: Expecting 41600 events.
[14:39:22.504] INFO: 41600 events read in total (3601ms).
[14:39:22.673] INFO: Test took 4808ms.
[14:39:22.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:23.032] INFO: PixTestAlive::aliveTest() done
[14:39:23.032] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[14:39:23.068] INFO: enter test to run
[14:39:42.189] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:39:42.189] INFO: running: highrate
[14:39:42.204] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:39:42.413] INFO: ----------------------------------------------------------------------
[14:39:42.413] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:39:42.413] INFO: ----------------------------------------------------------------------
[14:39:42.413] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:39:42.414] INFO: edge/corner pixel THR is adjusted
[14:39:42.414] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:39:43.373] INFO: Collecting data for 5 seconds...
[14:39:48.390] INFO: Done with hot pixel readout
[14:39:59.594] INFO: PixTest:: pg_setup set to default.
[14:39:59.595] INFO: 13 hot pixels found in step 0
[14:40:00.580] INFO: Collecting data for 5 seconds...
[14:40:05.597] INFO: Done with hot pixel readout
[14:40:16.807] INFO: PixTest:: pg_setup set to default.
[14:40:16.807] INFO: 8 hot pixels found in step 1
[14:40:17.796] INFO: Collecting data for 5 seconds...
[14:40:22.813] INFO: Done with hot pixel readout
[14:40:34.042] INFO: PixTest:: pg_setup set to default.
[14:40:34.043] INFO: 10 hot pixels found in step 2
[14:40:35.031] INFO: Collecting data for 5 seconds...
[14:40:40.048] INFO: Done with hot pixel readout
[14:40:51.163] INFO: PixTest:: pg_setup set to default.
[14:40:51.164] INFO: 8 hot pixels found in step 3
[14:40:52.153] INFO: Collecting data for 5 seconds...
[14:40:57.170] INFO: Done with hot pixel readout
[14:41:08.573] INFO: PixTest:: pg_setup set to default.
[14:41:08.574] INFO: 8 hot pixels found in step 4
[14:41:09.562] INFO: Collecting data for 5 seconds...
[14:41:14.581] INFO: Done with hot pixel readout
[14:41:25.910] INFO: PixTest:: pg_setup set to default.
[14:41:25.911] INFO: 8 hot pixels found in step 5
[14:41:26.899] INFO: Collecting data for 5 seconds...
[14:41:31.919] INFO: Done with hot pixel readout
[14:41:43.181] INFO: PixTest:: pg_setup set to default.
[14:41:43.182] INFO: 5 hot pixels found in step 6
[14:41:44.169] INFO: Collecting data for 5 seconds...
[14:41:49.188] INFO: Done with hot pixel readout
[14:42:00.407] INFO: PixTest:: pg_setup set to default.
[14:42:00.408] INFO: 3 hot pixels found in step 7
[14:42:01.395] INFO: Collecting data for 5 seconds...
[14:42:06.415] INFO: Done with hot pixel readout
[14:42:17.742] INFO: PixTest:: pg_setup set to default.
[14:42:17.743] INFO: 3 hot pixels found in step 8
[14:42:18.732] INFO: Collecting data for 5 seconds...
[14:42:23.752] INFO: Done with hot pixel readout
[14:42:34.952] INFO: PixTest:: pg_setup set to default.
[14:42:34.953] INFO: 0 hot pixels found in step 9
[14:42:34.985] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:42:34.989] INFO: PixTest::trimHotPixels() done
[14:42:35.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat
[14:42:35.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C1.dat
[14:42:35.017] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C2.dat
[14:42:35.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C3.dat
[14:42:35.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C4.dat
[14:42:35.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C5.dat
[14:42:35.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C6.dat
[14:42:35.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C7.dat
[14:42:35.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C8.dat
[14:42:35.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C9.dat
[14:42:35.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C10.dat
[14:42:35.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C11.dat
[14:42:35.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C12.dat
[14:42:35.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C13.dat
[14:42:35.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C14.dat
[14:42:35.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[14:42:35.118] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[14:42:35.128] INFO: enter test to run
[14:45:07.107] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:45:07.107] INFO: running: highrate
[14:45:07.112] INFO: ----------------------------------------------------------------------
[14:45:07.112] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:45:07.112] INFO: ----------------------------------------------------------------------
[14:45:07.112] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:45:07.112] INFO: edge/corner pixel THR is adjusted
[14:45:07.112] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:45:08.069] INFO: Collecting data for 1 seconds...
[14:45:09.073] INFO: Done with hot pixel readout
[14:45:12.832] INFO: PixTest:: pg_setup set to default.
[14:45:12.832] INFO: 0 hot pixels found in step 0
[14:45:12.838] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:45:12.939] INFO: PixTest::trimHotPixels() done
[14:45:12.939] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat
[14:45:12.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C1.dat
[14:45:12.954] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C2.dat
[14:45:12.960] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C3.dat
[14:45:12.965] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C4.dat
[14:45:12.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C5.dat
[14:45:12.976] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C6.dat
[14:45:12.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C7.dat
[14:45:12.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C8.dat
[14:45:12.991] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C9.dat
[14:45:12.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C10.dat
[14:45:13.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C11.dat
[14:45:13.007] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C12.dat
[14:45:13.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C13.dat
[14:45:13.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C14.dat
[14:45:13.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[14:45:13.028] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-2-40_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[14:45:13.038] INFO: enter test to run
[14:46:10.979] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:46:10.979] INFO: running: xray
[14:46:10.980] INFO: ----------------------------------------------------------------------
[14:46:10.980] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:46:10.980] INFO: ----------------------------------------------------------------------
[14:46:11.942] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:46:24.126] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:46:53.401] INFO: Resuming triggers.
[14:47:05.588] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:47:34.925] INFO: Resuming triggers.
[14:47:47.112] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:48:16.471] INFO: Resuming triggers.
[14:48:28.658] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:48:58.064] INFO: Resuming triggers.
[14:49:10.257] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:49:39.639] INFO: Resuming triggers.
[14:49:51.833] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:50:21.163] INFO: Resuming triggers.
[14:50:33.356] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:51:02.712] INFO: Resuming triggers.
[14:51:14.905] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:51:44.361] INFO: Resuming triggers.
[14:51:47.189] INFO: data taking finished, elapsed time: 100 seconds.
[14:51:54.328] INFO: PixTest:: pg_setup set to default.
[14:51:54.331] INFO: PixTestXray::doPhRun() done
[14:51:54.506] INFO: enter test to run
[14:53:21.120] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:53:21.120] INFO: running: xray
[14:53:21.121] INFO: ----------------------------------------------------------------------
[14:53:21.121] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:53:21.121] INFO: ----------------------------------------------------------------------
[14:53:22.085] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:53:29.600] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:54:00.773] INFO: Resuming triggers.
[14:54:08.293] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:54:39.407] INFO: Resuming triggers.
[14:54:46.922] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:55:17.648] INFO: Resuming triggers.
[14:55:25.165] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[14:55:56.232] INFO: Resuming triggers.
[14:56:03.748] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:56:35.275] INFO: Resuming triggers.
[14:56:42.795] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:57:14.254] INFO: Resuming triggers.
[14:57:21.774] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:57:52.995] INFO: Resuming triggers.
[14:58:00.510] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:58:30.884] INFO: Resuming triggers.
[14:58:38.406] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:59:08.570] INFO: Resuming triggers.
[14:59:16.090] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:59:46.254] INFO: Resuming triggers.
[14:59:53.776] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:00:24.026] INFO: Resuming triggers.
[15:00:31.547] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:01:01.745] INFO: Resuming triggers.
[15:01:09.270] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:01:39.612] INFO: Resuming triggers.
[15:01:42.240] INFO: data taking finished, elapsed time: 100 seconds.
[15:01:53.077] INFO: PixTest:: pg_setup set to default.
[15:01:53.080] INFO: PixTestXray::doPhRun() done
[15:01:53.226] INFO: enter test to run
[15:02:14.668] INFO: test: HighRate no parameter change
[15:02:14.668] INFO: running: highrate
[15:02:14.683] INFO: ----------------------------------------------------------------------
[15:02:14.684] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:02:14.684] INFO: ----------------------------------------------------------------------
[15:02:14.840] INFO: Expecting 768 events.
[15:02:15.973] INFO: 768 events read in total (418ms).
[15:02:15.974] INFO: Test took 1269ms.
[15:02:16.777] INFO: Expecting 41600 events.
[15:02:19.843] INFO: 41600 events read in total (2539ms).
[15:02:19.845] INFO: Test took 3855ms.
[15:02:19.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:20.611] INFO: Expecting 41600 events.
[15:02:23.770] INFO: 41600 events read in total (2633ms).
[15:02:23.771] INFO: Test took 3881ms.
[15:02:23.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:24.536] INFO: Expecting 41600 events.
[15:02:27.715] INFO: 41600 events read in total (2652ms).
[15:02:27.716] INFO: Test took 3899ms.
[15:02:27.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:28.477] INFO: Expecting 41600 events.
[15:02:31.674] INFO: 41600 events read in total (2670ms).
[15:02:31.675] INFO: Test took 3914ms.
[15:02:31.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:32.435] INFO: Expecting 41600 events.
[15:02:35.622] INFO: 41600 events read in total (2660ms).
[15:02:35.623] INFO: Test took 3902ms.
[15:02:35.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:36.383] INFO: Expecting 41600 events.
[15:02:39.563] INFO: 41600 events read in total (2653ms).
[15:02:39.564] INFO: Test took 3896ms.
[15:02:39.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:40.328] INFO: Expecting 41600 events.
[15:02:43.541] INFO: 41600 events read in total (2686ms).
[15:02:43.542] INFO: Test took 3931ms.
[15:02:43.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:44.301] INFO: Expecting 41600 events.
[15:02:47.489] INFO: 41600 events read in total (2661ms).
[15:02:47.490] INFO: Test took 3903ms.
[15:02:47.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:48.249] INFO: Expecting 41600 events.
[15:02:51.463] INFO: 41600 events read in total (2687ms).
[15:02:51.464] INFO: Test took 3928ms.
[15:02:51.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:52.225] INFO: Expecting 41600 events.
[15:02:55.414] INFO: 41600 events read in total (2662ms).
[15:02:55.415] INFO: Test took 3907ms.
[15:02:55.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:56.180] INFO: Expecting 41600 events.
[15:02:59.375] INFO: 41600 events read in total (2668ms).
[15:02:59.376] INFO: Test took 3915ms.
[15:02:59.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:00.139] INFO: Expecting 41600 events.
[15:03:03.319] INFO: 41600 events read in total (2653ms).
[15:03:03.320] INFO: Test took 3898ms.
[15:03:03.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:04.082] INFO: Expecting 41600 events.
[15:03:07.269] INFO: 41600 events read in total (2660ms).
[15:03:07.270] INFO: Test took 3903ms.
[15:03:07.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:08.032] INFO: Expecting 41600 events.
[15:03:11.238] INFO: 41600 events read in total (2679ms).
[15:03:11.239] INFO: Test took 3923ms.
[15:03:11.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:11.999] INFO: Expecting 41600 events.
[15:03:15.197] INFO: 41600 events read in total (2671ms).
[15:03:15.198] INFO: Test took 3913ms.
[15:03:15.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:15.958] INFO: Expecting 41600 events.
[15:03:19.159] INFO: 41600 events read in total (2674ms).
[15:03:19.160] INFO: Test took 3915ms.
[15:03:19.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:19.920] INFO: Expecting 41600 events.
[15:03:23.120] INFO: 41600 events read in total (2673ms).
[15:03:23.121] INFO: Test took 3914ms.
[15:03:23.150] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:23.884] INFO: Expecting 41600 events.
[15:03:27.067] INFO: 41600 events read in total (2657ms).
[15:03:27.068] INFO: Test took 3901ms.
[15:03:27.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:27.829] INFO: Expecting 41600 events.
[15:03:31.016] INFO: 41600 events read in total (2660ms).
[15:03:31.017] INFO: Test took 3902ms.
[15:03:31.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:31.780] INFO: Expecting 41600 events.
[15:03:34.853] INFO: 41600 events read in total (2546ms).
[15:03:34.854] INFO: Test took 3790ms.
[15:03:34.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:35.256] INFO: enter test to run
[15:03:49.003] INFO: test: HighRate no parameter change
[15:03:49.004] INFO: running: highrate
[15:03:49.005] INFO: ----------------------------------------------------------------------
[15:03:49.005] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:03:49.005] INFO: ----------------------------------------------------------------------
[15:03:49.627] INFO: Expecting 208000 events.
[15:04:01.256] INFO: 208000 events read in total (11102ms).
[15:04:01.259] INFO: Test took 12244ms.
[15:04:01.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:01.624] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[15:04:01.624] INFO: number of red-efficiency pixels: 65 41 46 119 118 126 104 60 60 101 80 79 72 46 14 21
[15:04:01.624] INFO: number of X-ray hits detected: 53909 37085 55487 90138 94432 98502 98449 71750 64314 83360 74707 64165 64744 40638 17560 18166
[15:04:01.624] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:04:01.624] INFO: number of Vcal hits detected: 207935 207957 207954 207880 207879 207871 207894 207940 207938 207897 207919 207920 207927 207904 207986 207979
[15:04:01.624] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:04:01.624] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:04:01.624] INFO: X-ray hit rate [MHz/cm2]: 15.8 10.9 16.3 26.4 27.7 28.9 28.9 21.0 18.9 24.4 21.9 18.8 19.0 11.9 5.1 5.3
[15:04:01.624] INFO: PixTestHighRate::doXPixelAlive() done
[15:04:01.668] INFO: PixTest:: pg_setup set to default.
[15:04:01.683] INFO: enter test to run
[15:04:15.027] INFO: test: HighRate no parameter change
[15:04:15.027] INFO: running: highrate
[15:04:15.028] INFO: ----------------------------------------------------------------------
[15:04:15.028] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:04:15.028] INFO: ----------------------------------------------------------------------
[15:04:15.643] INFO: Expecting 208000 events.
[15:04:28.614] INFO: 208000 events read in total (12444ms).
[15:04:28.619] INFO: Test took 13582ms.
[15:04:28.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:29.144] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[15:04:29.144] INFO: number of red-efficiency pixels: 170 103 150 255 357 355 336 208 163 273 277 170 201 105 46 35
[15:04:29.144] INFO: number of X-ray hits detected: 111139 76111 114415 185515 194082 203740 202678 147231 133146 171224 152595 130760 133457 84040 36508 38009
[15:04:29.144] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:04:29.144] INFO: number of Vcal hits detected: 207822 207891 207844 207733 207626 207630 207647 207781 207831 207711 207715 207820 207797 207843 207954 207965
[15:04:29.144] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:04:29.144] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[15:04:29.144] INFO: X-ray hit rate [MHz/cm2]: 32.6 22.3 33.5 54.4 56.9 59.7 59.4 43.2 39.0 50.2 44.7 38.3 39.1 24.6 10.7 11.1
[15:04:29.144] INFO: PixTestHighRate::doXPixelAlive() done
[15:04:29.189] INFO: PixTest:: pg_setup set to default.
[15:04:29.202] INFO: enter test to run
[15:05:17.139] INFO: test: HighRate no parameter change
[15:05:17.139] INFO: running: highrate
[15:05:17.140] INFO: ----------------------------------------------------------------------
[15:05:17.140] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:05:17.140] INFO: ----------------------------------------------------------------------
[15:05:17.757] INFO: Expecting 208000 events.
[15:05:32.253] INFO: 208000 events read in total (13969ms).
[15:05:32.259] INFO: Test took 15110ms.
[15:05:32.627] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:32.949] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[15:05:32.949] INFO: number of red-efficiency pixels: 326 160 321 552 840 836 759 409 305 584 543 384 404 190 75 75
[15:05:32.949] INFO: number of X-ray hits detected: 167096 115714 173466 280017 293896 308722 307580 223439 202328 260574 232222 199207 201461 127476 55216 58074
[15:05:32.949] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:05:32.949] INFO: number of Vcal hits detected: 207623 207829 207637 207386 207039 206975 207108 207543 207678 207355 207400 207584 207568 207745 207924 207923
[15:05:32.949] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.6 99.6 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[15:05:32.949] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.5 99.5 99.6 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[15:05:32.949] INFO: X-ray hit rate [MHz/cm2]: 49.0 33.9 50.8 82.1 86.1 90.5 90.2 65.5 59.3 76.4 68.1 58.4 59.0 37.4 16.2 17.0
[15:05:32.949] INFO: PixTestHighRate::doXPixelAlive() done
[15:05:33.002] INFO: PixTest:: pg_setup set to default.
[15:05:33.018] INFO: enter test to run
[15:06:02.562] INFO: test: exit no parameter change
[15:06:02.979] QUIET: Connection to board 33 closed.
[15:06:03.013] INFO: pXar: this is the end, my friend