[11:44:26.774] INFO: *** Welcome to pxar ***
[11:44:26.774] INFO: *** Today: 2016/06/23
[11:44:26.792] INFO: *** Version: v1.9.0-814-g7497
[11:44:26.793] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//dacParameters35_C15.dat
[11:44:26.815] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:44:26.816] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//defaultMaskFile.dat
[11:44:26.816] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C15.dat
[11:44:26.903] INFO: clk: 4
[11:44:26.903] INFO: ctr: 4
[11:44:26.903] INFO: sda: 19
[11:44:26.903] INFO: tin: 9
[11:44:26.903] INFO: level: 15
[11:44:26.903] INFO: triggerdelay: 0
[11:44:26.903] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:44:26.903] INFO: Log level: INFO
[11:44:26.919] QUIET: Connection to board DTB_WREK4U opened.
[11:44:26.922] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[11:44:26.925] INFO: RPC call hashes of host and DTB match: 398089610
[11:44:28.458] INFO: DUT info:
[11:44:28.459] INFO: The DUT currently contains the following objects:
[11:44:28.459] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:28.459] INFO: TBM Core alpha (0): 7 registers set
[11:44:28.459] INFO: TBM Core beta (1): 7 registers set
[11:44:28.459] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:44:28.459] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.459] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.460] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:44:28.863] INFO: enter 'restricted' command line mode
[11:44:28.863] INFO: enter test to run
[11:44:35.371] INFO: test: PixelAlive no parameter change
[11:44:35.371] INFO: running: pixelalive
[11:44:35.380] INFO: ----------------------------------------------------------------------
[11:44:35.380] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:44:35.380] INFO: ----------------------------------------------------------------------
[11:44:35.708] INFO: Expecting 41600 events.
[11:44:40.026] INFO: 41600 events read in total (3599ms).
[11:44:40.194] INFO: Test took 4811ms.
[11:44:40.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:40.473] INFO: PixTestAlive::aliveTest() done
[11:44:40.473] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:44:40.508] INFO: enter test to run
[11:45:00.347] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:45:00.347] INFO: running: highrate
[11:45:00.367] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:45:00.616] INFO: ----------------------------------------------------------------------
[11:45:00.616] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:45:00.616] INFO: ----------------------------------------------------------------------
[11:45:00.616] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:45:00.616] INFO: edge/corner pixel THR is adjusted
[11:45:00.616] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:45:01.574] INFO: Collecting data for 5 seconds...
[11:45:06.591] INFO: Done with hot pixel readout
[11:45:17.972] INFO: PixTest:: pg_setup set to default.
[11:45:17.973] INFO: 20 hot pixels found in step 0
[11:45:18.958] INFO: Collecting data for 5 seconds...
[11:45:23.977] INFO: Done with hot pixel readout
[11:45:35.328] INFO: PixTest:: pg_setup set to default.
[11:45:35.329] INFO: 19 hot pixels found in step 1
[11:45:36.320] INFO: Collecting data for 5 seconds...
[11:45:41.338] INFO: Done with hot pixel readout
[11:45:52.539] INFO: PixTest:: pg_setup set to default.
[11:45:52.540] INFO: 21 hot pixels found in step 2
[11:45:53.527] INFO: Collecting data for 5 seconds...
[11:45:58.547] INFO: Done with hot pixel readout
[11:46:09.994] INFO: PixTest:: pg_setup set to default.




[11:46:09.995] INFO: 19 hot pixels found in step 3
[11:46:10.983] INFO: Collecting data for 5 seconds...
[11:46:16.004] INFO: Done with hot pixel readout
[11:46:27.554] INFO: PixTest:: pg_setup set to default.


[11:46:27.555] INFO: 14 hot pixels found in step 4
[11:46:28.543] INFO: Collecting data for 5 seconds...
[11:46:33.562] INFO: Done with hot pixel readout
[11:46:44.926] INFO: PixTest:: pg_setup set to default.



[11:46:44.927] INFO: 9 hot pixels found in step 5
[11:46:45.916] INFO: Collecting data for 5 seconds...
[11:46:50.934] INFO: Done with hot pixel readout
[11:47:02.280] INFO: PixTest:: pg_setup set to default.



[11:47:02.281] INFO: 8 hot pixels found in step 6
[11:47:03.270] INFO: Collecting data for 5 seconds...
[11:47:08.288] INFO: Done with hot pixel readout
[11:47:19.786] INFO: PixTest:: pg_setup set to default.




[11:47:19.787] INFO: 9 hot pixels found in step 7
[11:47:20.775] INFO: Collecting data for 5 seconds...
[11:47:25.795] INFO: Done with hot pixel readout
[11:47:37.087] INFO: PixTest:: pg_setup set to default.


[11:47:37.088] INFO: 3 hot pixels found in step 8
[11:47:38.075] INFO: Collecting data for 5 seconds...
[11:47:43.093] INFO: Done with hot pixel readout
[11:47:54.415] INFO: PixTest:: pg_setup set to default.



[11:47:54.415] INFO: 4 hot pixels found in step 9
[11:47:55.403] INFO: Collecting data for 5 seconds...
[11:48:00.420] INFO: Done with hot pixel readout
[11:48:11.732] INFO: PixTest:: pg_setup set to default.





[11:48:11.733] INFO: 8 hot pixels found in step 10
[11:48:12.719] INFO: Collecting data for 5 seconds...
[11:48:17.735] INFO: Done with hot pixel readout
[11:48:29.069] INFO: PixTest:: pg_setup set to default.




[11:48:29.070] INFO: 4 hot pixels found in step 11
[11:48:29.102] INFO: 4 hot pixels could not be trimmed and have been masked.
[11:48:29.105] INFO: PixTest::trimHotPixels() done
[11:48:29.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C0.dat
[11:48:29.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C1.dat
[11:48:29.116] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C2.dat
[11:48:29.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C3.dat
[11:48:29.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C4.dat
[11:48:29.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C5.dat
[11:48:29.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C6.dat
[11:48:29.144] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C7.dat
[11:48:29.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C8.dat
[11:48:29.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C9.dat
[11:48:29.160] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C10.dat
[11:48:29.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C11.dat
[11:48:29.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C12.dat
[11:48:29.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C13.dat
[11:48:29.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C14.dat
[11:48:29.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C15.dat
[11:48:29.191] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//defaultMaskFile.dat
[11:48:29.201] INFO: enter test to run
[11:49:34.073] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:49:34.073] INFO: running: highrate
[11:49:34.078] INFO: ----------------------------------------------------------------------
[11:49:34.078] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:49:34.078] INFO: ----------------------------------------------------------------------
[11:49:34.078] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:49:34.078] INFO: edge/corner pixel THR is adjusted
[11:49:34.078] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:49:35.036] INFO: Collecting data for 1 seconds...
[11:49:36.039] INFO: Done with hot pixel readout
[11:49:39.760] INFO: PixTest:: pg_setup set to default.
[11:49:39.761] INFO: 0 hot pixels found in step 0
[11:49:39.766] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:49:39.866] INFO: PixTest::trimHotPixels() done
[11:49:39.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C0.dat
[11:49:39.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C1.dat
[11:49:39.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C2.dat
[11:49:39.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C3.dat
[11:49:39.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C4.dat
[11:49:39.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C5.dat
[11:49:39.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C6.dat
[11:49:39.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C7.dat
[11:49:39.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C8.dat
[11:49:39.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C9.dat
[11:49:39.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C10.dat
[11:49:39.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C11.dat
[11:49:39.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C12.dat
[11:49:39.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C13.dat
[11:49:39.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C14.dat
[11:49:39.953] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C15.dat
[11:49:39.958] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-42_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//defaultMaskFile.dat
[11:49:39.969] INFO: enter test to run
[11:50:25.041] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:50:25.041] INFO: running: xray
[11:50:25.042] INFO: ----------------------------------------------------------------------
[11:50:25.042] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:50:25.042] INFO: ----------------------------------------------------------------------
[11:50:26.005] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:50:38.086] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[11:51:07.263] INFO: Resuming triggers.
[11:51:19.347] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[11:51:48.664] INFO: Resuming triggers.
[11:52:00.746] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[11:52:29.870] INFO: Resuming triggers.
[11:52:41.953] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[11:53:11.124] INFO: Resuming triggers.
[11:53:23.207] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[11:53:52.376] INFO: Resuming triggers.
[11:54:04.457] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[11:54:33.626] INFO: Resuming triggers.
[11:54:45.705] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[11:55:14.901] INFO: Resuming triggers.
[11:55:26.982] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[11:55:56.236] INFO: Resuming triggers.
[11:55:59.906] INFO: data taking finished, elapsed time: 100 seconds.
[11:56:09.105] INFO: PixTest:: pg_setup set to default.
[11:56:09.108] INFO: PixTestXray::doPhRun() done
[11:56:09.243] INFO: enter test to run
[11:56:40.775] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:56:40.775] INFO: running: xray
[11:56:40.776] INFO: ----------------------------------------------------------------------
[11:56:40.776] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:56:40.776] INFO: ----------------------------------------------------------------------
[11:56:41.739] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:56:49.118] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[11:57:20.289] INFO: Resuming triggers.
[11:57:27.671] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[11:57:58.791] INFO: Resuming triggers.
[11:58:06.175] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:58:37.243] INFO: Resuming triggers.
[11:58:44.628] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[11:59:16.331] INFO: Resuming triggers.
[11:59:23.717] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[11:59:53.853] INFO: Resuming triggers.
[12:00:01.238] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:00:31.331] INFO: Resuming triggers.
[12:00:38.718] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:01:08.782] INFO: Resuming triggers.
[12:01:16.168] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:01:46.259] INFO: Resuming triggers.
[12:01:53.644] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:02:23.772] INFO: Resuming triggers.
[12:02:31.158] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:03:01.204] INFO: Resuming triggers.
[12:03:08.589] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:03:38.569] INFO: Resuming triggers.
[12:03:45.953] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:04:16.033] INFO: Resuming triggers.
[12:04:23.418] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:04:53.494] INFO: Resuming triggers.
[12:04:57.836] INFO: data taking finished, elapsed time: 100 seconds.
[12:05:15.945] INFO: PixTest:: pg_setup set to default.
[12:05:15.948] INFO: PixTestXray::doPhRun() done
[12:05:16.096] INFO: enter test to run
[12:06:01.003] INFO: test: HighRate no parameter change
[12:06:01.003] INFO: running: highrate
[12:06:01.004] INFO: ----------------------------------------------------------------------
[12:06:01.004] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:06:01.004] INFO: ----------------------------------------------------------------------
[12:06:01.162] INFO: Expecting 768 events.
[12:06:02.296] INFO: 768 events read in total (418ms).
[12:06:02.297] INFO: Test took 1269ms.
[12:06:03.099] INFO: Expecting 41600 events.
[12:06:06.162] INFO: 41600 events read in total (2536ms).
[12:06:06.163] INFO: Test took 3859ms.
[12:06:06.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:06.926] INFO: Expecting 41600 events.
[12:06:10.097] INFO: 41600 events read in total (2645ms).
[12:06:10.098] INFO: Test took 3888ms.
[12:06:10.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:10.856] INFO: Expecting 41600 events.
[12:06:14.058] INFO: 41600 events read in total (2675ms).
[12:06:14.059] INFO: Test took 3913ms.
[12:06:14.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:14.818] INFO: Expecting 41600 events.
[12:06:18.010] INFO: 41600 events read in total (2666ms).
[12:06:18.011] INFO: Test took 3906ms.
[12:06:18.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:18.775] INFO: Expecting 41600 events.
[12:06:21.969] INFO: 41600 events read in total (2667ms).
[12:06:21.969] INFO: Test took 3910ms.
[12:06:22.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:22.732] INFO: Expecting 41600 events.
[12:06:25.931] INFO: 41600 events read in total (2672ms).
[12:06:25.932] INFO: Test took 3907ms.
[12:06:25.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:26.696] INFO: Expecting 41600 events.
[12:06:29.888] INFO: 41600 events read in total (2665ms).
[12:06:29.889] INFO: Test took 3910ms.
[12:06:29.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:30.651] INFO: Expecting 41600 events.
[12:06:33.836] INFO: 41600 events read in total (2658ms).
[12:06:33.837] INFO: Test took 3901ms.
[12:06:33.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:34.599] INFO: Expecting 41600 events.
[12:06:37.810] INFO: 41600 events read in total (2684ms).
[12:06:37.811] INFO: Test took 3928ms.
[12:06:37.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:38.574] INFO: Expecting 41600 events.
[12:06:41.771] INFO: 41600 events read in total (2670ms).
[12:06:41.772] INFO: Test took 3915ms.
[12:06:41.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:42.536] INFO: Expecting 41600 events.
[12:06:45.730] INFO: 41600 events read in total (2667ms).
[12:06:45.731] INFO: Test took 3913ms.
[12:06:45.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:46.494] INFO: Expecting 41600 events.
[12:06:49.677] INFO: 41600 events read in total (2656ms).
[12:06:49.678] INFO: Test took 3901ms.
[12:06:49.708] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:50.442] INFO: Expecting 41600 events.
[12:06:53.591] INFO: 41600 events read in total (2622ms).
[12:06:53.592] INFO: Test took 3868ms.
[12:06:53.622] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:54.356] INFO: Expecting 41600 events.
[12:06:57.536] INFO: 41600 events read in total (2653ms).
[12:06:57.537] INFO: Test took 3899ms.
[12:06:57.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:58.301] INFO: Expecting 41600 events.
[12:07:01.473] INFO: 41600 events read in total (2645ms).
[12:07:01.474] INFO: Test took 3890ms.
[12:07:01.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:02.237] INFO: Expecting 41600 events.
[12:07:05.434] INFO: 41600 events read in total (2670ms).
[12:07:05.435] INFO: Test took 3916ms.
[12:07:05.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:06.199] INFO: Expecting 41600 events.
[12:07:09.402] INFO: 41600 events read in total (2676ms).
[12:07:09.403] INFO: Test took 3920ms.
[12:07:09.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:10.163] INFO: Expecting 41600 events.
[12:07:13.355] INFO: 41600 events read in total (2665ms).
[12:07:13.356] INFO: Test took 3906ms.
[12:07:13.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:14.121] INFO: Expecting 41600 events.
[12:07:17.277] INFO: 41600 events read in total (2629ms).
[12:07:17.278] INFO: Test took 3875ms.
[12:07:17.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:18.042] INFO: Expecting 41600 events.
[12:07:21.052] INFO: 41600 events read in total (2483ms).
[12:07:21.053] INFO: Test took 3729ms.
[12:07:21.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:21.455] INFO: enter test to run
[12:07:25.770] INFO: test: HighRate no parameter change
[12:07:25.770] INFO: running: highrate
[12:07:25.771] INFO: ----------------------------------------------------------------------
[12:07:25.771] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:07:25.771] INFO: ----------------------------------------------------------------------
[12:07:26.384] INFO: Expecting 208000 events.
[12:07:38.037] INFO: 208000 events read in total (11126ms).
[12:07:38.040] INFO: Test took 12262ms.
[12:07:38.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:38.410] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:07:38.410] INFO: number of red-efficiency pixels: 46 50 66 106 138 110 142 91 59 87 86 95 68 43 14 25
[12:07:38.410] INFO: number of X-ray hits detected: 49934 34520 57021 91623 99943 100128 101482 68634 63903 83124 84358 71244 70228 41893 15357 20641
[12:07:38.410] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:07:38.410] INFO: number of Vcal hits detected: 207952 207949 207932 207893 207859 207869 207856 207908 207939 207911 207912 207901 207932 207957 207986 207975
[12:07:38.410] INFO: Vcal hit fiducial efficiency (%): 100.0 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
[12:07:38.410] 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
[12:07:38.410] INFO: X-ray hit rate [MHz/cm2]: 14.6 10.1 16.7 26.9 29.3 29.3 29.7 20.1 18.7 24.4 24.7 20.9 20.6 12.3 4.5 6.1
[12:07:38.410] INFO: PixTestHighRate::doXPixelAlive() done
[12:07:38.457] INFO: PixTest:: pg_setup set to default.
[12:07:38.467] INFO: enter test to run
[12:08:05.138] INFO: test: HighRate no parameter change
[12:08:05.138] INFO: running: highrate
[12:08:05.139] INFO: ----------------------------------------------------------------------
[12:08:05.139] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:08:05.139] INFO: ----------------------------------------------------------------------
[12:08:05.761] INFO: Expecting 208000 events.
[12:08:18.747] INFO: 208000 events read in total (12459ms).
[12:08:18.752] INFO: Test took 13604ms.
[12:08:19.009] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:19.297] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:08:19.297] INFO: number of red-efficiency pixels: 164 88 175 344 401 311 445 272 185 311 318 219 160 110 32 50
[12:08:19.297] INFO: number of X-ray hits detected: 102064 71274 116858 188946 206028 205308 210092 141538 131347 171256 173784 147257 145623 86534 32022 42655
[12:08:19.297] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:08:19.297] INFO: number of Vcal hits detected: 207820 207906 207814 207633 207568 207634 207517 207709 207810 207667 207659 207772 207835 207884 207967 207950
[12:08:19.297] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[12:08:19.297] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:08:19.298] INFO: X-ray hit rate [MHz/cm2]: 29.9 20.9 34.3 55.4 60.4 60.2 61.6 41.5 38.5 50.2 50.9 43.2 42.7 25.4 9.4 12.5
[12:08:19.298] INFO: PixTestHighRate::doXPixelAlive() done
[12:08:19.343] INFO: PixTest:: pg_setup set to default.
[12:08:19.359] INFO: enter test to run
[12:08:42.234] INFO: test: HighRate no parameter change
[12:08:42.234] INFO: running: highrate
[12:08:42.235] INFO: ----------------------------------------------------------------------
[12:08:42.235] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:08:42.235] INFO: ----------------------------------------------------------------------
[12:08:42.854] INFO: Expecting 208000 events.
[12:08:57.522] INFO: 208000 events read in total (14142ms).
[12:08:57.529] INFO: Test took 15285ms.
[12:08:57.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:58.253] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:08:58.253] INFO: number of red-efficiency pixels: 298 217 356 824 941 722 1007 576 416 662 723 512 343 200 55 72
[12:08:58.253] INFO: number of X-ray hits detected: 154326 107515 176780 284771 310735 311516 316656 215238 199769 259563 262471 223680 221607 130222 48634 64425
[12:08:58.253] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:08:58.253] INFO: number of Vcal hits detected: 207662 207768 207592 207027 206885 207129 206766 207301 207543 207249 207182 207433 207636 207787 207945 207925
[12:08:58.253] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.6 99.5 99.6 99.5 99.7 99.8 99.7 99.6 99.8 99.8 99.9 100.0 100.0
[12:08:58.253] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.5 99.6 99.4 99.7 99.8 99.6 99.6 99.7 99.8 99.9 100.0 100.0
[12:08:58.253] INFO: X-ray hit rate [MHz/cm2]: 45.2 31.5 51.8 83.5 91.1 91.3 92.8 63.1 58.6 76.1 76.9 65.6 65.0 38.2 14.3 18.9
[12:08:58.253] INFO: PixTestHighRate::doXPixelAlive() done
[12:08:58.298] INFO: PixTest:: pg_setup set to default.
[12:08:58.319] INFO: enter test to run
[12:09:30.041] INFO: test: exit no parameter change
[12:09:30.324] QUIET: Connection to board 32 closed.
[12:09:30.325] INFO: pXar: this is the end, my friend