[14:38:47.275] INFO: *** Welcome to pxar ***
[14:38:47.275] INFO: *** Today: 2016/08/24
[14:38:47.289] INFO: *** Version: v1.9.0-818-g96727
[14:38:47.289] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//dacParameters35_C15.dat
[14:38:47.290] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:38:47.290] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:47.290] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:47.360] INFO: clk: 4
[14:38:47.360] INFO: ctr: 4
[14:38:47.360] INFO: sda: 19
[14:38:47.360] INFO: tin: 9
[14:38:47.360] INFO: level: 15
[14:38:47.360] INFO: triggerdelay: 0
[14:38:47.360] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:38:47.360] INFO: Log level: INFO
[14:38:47.376] QUIET: Connection to board DTB_WREK4U opened.
[14:38:47.379] 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:
------------------------------------------------------
[14:38:47.382] INFO: RPC call hashes of host and DTB match: 398089610
[14:38:48.916] INFO: DUT info:
[14:38:48.916] INFO: The DUT currently contains the following objects:
[14:38:48.916] INFO: 2 TBM Cores tbm08c (2 ON)
[14:38:48.916] INFO: TBM Core alpha (0): 7 registers set
[14:38:48.916] INFO: TBM Core beta (1): 7 registers set
[14:38:48.916] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:38:48.916] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.916] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:48.917] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:49.320] INFO: enter 'restricted' command line mode
[14:38:49.320] INFO: enter test to run
[14:39:05.701] INFO: test: PixelAlive no parameter change
[14:39:05.701] INFO: running: pixelalive
[14:39:05.710] INFO: ----------------------------------------------------------------------
[14:39:05.710] 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:05.710] INFO: ----------------------------------------------------------------------
[14:39:06.034] INFO: Expecting 41600 events.
[14:39:10.251] INFO: 41600 events read in total (3498ms).
[14:39:10.416] INFO: Test took 4703ms.
[14:39:10.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:10.692] INFO: PixTestAlive::aliveTest() done
[14:39:10.692] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[14:39:10.725] INFO: enter test to run
[14:39:29.637] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:39:29.637] INFO: running: highrate
[14:39:29.638] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:39:29.875] INFO: ----------------------------------------------------------------------
[14:39:29.875] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:39:29.875] INFO: ----------------------------------------------------------------------
[14:39:29.875] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:39:29.875] INFO: edge/corner pixel THR is adjusted
[14:39:29.875] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:39:30.833] INFO: Collecting data for 5 seconds...
[14:39:35.853] INFO: Done with hot pixel readout
[14:39:46.757] INFO: PixTest:: pg_setup set to default.
[14:39:46.758] INFO: 18 hot pixels found in step 0
[14:39:47.744] INFO: Collecting data for 5 seconds...
[14:39:52.763] INFO: Done with hot pixel readout
[14:40:03.807] INFO: PixTest:: pg_setup set to default.
[14:40:03.808] INFO: 19 hot pixels found in step 1
[14:40:04.795] INFO: Collecting data for 5 seconds...
[14:40:09.813] INFO: Done with hot pixel readout
[14:40:20.539] INFO: PixTest:: pg_setup set to default.
[14:40:20.540] INFO: 17 hot pixels found in step 2
[14:40:21.527] INFO: Collecting data for 5 seconds...
[14:40:26.546] INFO: Done with hot pixel readout
[14:40:37.780] INFO: PixTest:: pg_setup set to default.
[14:40:37.781] INFO: 19 hot pixels found in step 3
[14:40:38.769] INFO: Collecting data for 5 seconds...
[14:40:43.788] INFO: Done with hot pixel readout
[14:40:55.055] INFO: PixTest:: pg_setup set to default.
[14:40:55.056] INFO: 18 hot pixels found in step 4
[14:40:56.044] INFO: Collecting data for 5 seconds...
[14:41:01.064] INFO: Done with hot pixel readout
[14:41:12.398] INFO: PixTest:: pg_setup set to default.

[14:41:12.398] INFO: 17 hot pixels found in step 5
[14:41:13.386] INFO: Collecting data for 5 seconds...
[14:41:18.404] INFO: Done with hot pixel readout
[14:41:29.618] INFO: PixTest:: pg_setup set to default.




[14:41:29.619] INFO: 16 hot pixels found in step 6
[14:41:30.606] INFO: Collecting data for 5 seconds...
[14:41:35.625] INFO: Done with hot pixel readout
[14:41:46.764] INFO: PixTest:: pg_setup set to default.






[14:41:46.765] INFO: 15 hot pixels found in step 7
[14:41:47.752] INFO: Collecting data for 5 seconds...
[14:41:52.773] INFO: Done with hot pixel readout
[14:42:04.140] INFO: PixTest:: pg_setup set to default.







[14:42:04.141] INFO: 11 hot pixels found in step 8
[14:42:05.128] INFO: Collecting data for 5 seconds...
[14:42:10.150] INFO: Done with hot pixel readout
[14:42:21.077] INFO: PixTest:: pg_setup set to default.






[14:42:21.078] INFO: 9 hot pixels found in step 9
[14:42:22.065] INFO: Collecting data for 5 seconds...
[14:42:27.089] INFO: Done with hot pixel readout
[14:42:38.180] INFO: PixTest:: pg_setup set to default.






[14:42:38.181] INFO: 9 hot pixels found in step 10
[14:42:39.170] INFO: Collecting data for 5 seconds...
[14:42:44.186] INFO: Done with hot pixel readout
[14:42:55.305] INFO: PixTest:: pg_setup set to default.








[14:42:55.306] INFO: 9 hot pixels found in step 11
[14:42:56.293] INFO: Collecting data for 5 seconds...
[14:43:01.311] INFO: Done with hot pixel readout
[14:43:12.568] INFO: PixTest:: pg_setup set to default.







[14:43:12.569] INFO: 10 hot pixels found in step 12
[14:43:13.555] INFO: Collecting data for 5 seconds...
[14:43:18.572] INFO: Done with hot pixel readout
[14:43:29.800] INFO: PixTest:: pg_setup set to default.








[14:43:29.801] INFO: 8 hot pixels found in step 13
[14:43:29.833] INFO: 8 hot pixels could not be trimmed and have been masked.
[14:43:29.871] INFO: PixTest::trimHotPixels() done
[14:43:29.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C0.dat
[14:43:29.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C1.dat
[14:43:29.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C2.dat
[14:43:29.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C3.dat
[14:43:29.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C4.dat
[14:43:29.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C5.dat
[14:43:29.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C6.dat
[14:43:29.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C7.dat
[14:43:29.919] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C8.dat
[14:43:29.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C9.dat
[14:43:29.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C10.dat
[14:43:29.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C11.dat
[14:43:29.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C12.dat
[14:43:29.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C13.dat
[14:43:29.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C14.dat
[14:43:29.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C15.dat
[14:43:29.962] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//defaultMaskFile.dat
[14:43:29.973] INFO: enter test to run
[14:44:32.787] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:44:32.787] INFO: running: highrate
[14:44:32.792] INFO: ----------------------------------------------------------------------
[14:44:32.792] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:44:32.792] INFO: ----------------------------------------------------------------------
[14:44:32.792] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:44:32.792] INFO: edge/corner pixel THR is adjusted
[14:44:32.792] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:44:33.750] INFO: Collecting data for 1 seconds...
[14:44:34.753] INFO: Done with hot pixel readout
[14:44:38.528] INFO: PixTest:: pg_setup set to default.
[14:44:38.529] INFO: 0 hot pixels found in step 0
[14:44:38.535] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:44:38.629] INFO: PixTest::trimHotPixels() done
[14:44:38.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C0.dat
[14:44:38.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C1.dat
[14:44:38.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C2.dat
[14:44:38.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C3.dat
[14:44:38.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C4.dat
[14:44:38.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C5.dat
[14:44:38.669] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C6.dat
[14:44:38.674] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C7.dat
[14:44:38.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C8.dat
[14:44:38.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C9.dat
[14:44:38.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C10.dat
[14:44:38.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C11.dat
[14:44:38.702] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C12.dat
[14:44:38.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C13.dat
[14:44:38.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C14.dat
[14:44:38.718] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C15.dat
[14:44:38.724] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-16_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//defaultMaskFile.dat
[14:44:38.734] INFO: enter test to run
[14:44:54.515] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:44:54.515] INFO: running: xray
[14:44:54.516] INFO: ----------------------------------------------------------------------
[14:44:54.516] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:44:54.516] INFO: ----------------------------------------------------------------------
[14:44:55.479] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:45:07.559] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:45:37.161] INFO: Resuming triggers.
[14:45:49.241] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:46:18.562] INFO: Resuming triggers.
[14:46:30.646] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:47:00.078] INFO: Resuming triggers.
[14:47:12.166] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:47:41.560] INFO: Resuming triggers.
[14:47:53.647] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:48:23.030] INFO: Resuming triggers.
[14:48:35.116] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:49:04.480] INFO: Resuming triggers.
[14:49:16.566] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:49:45.948] INFO: Resuming triggers.
[14:49:58.037] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:50:27.388] INFO: Resuming triggers.
[14:50:31.047] INFO: data taking finished, elapsed time: 100 seconds.
[14:50:40.347] INFO: PixTest:: pg_setup set to default.
[14:50:40.350] INFO: PixTestXray::doPhRun() done
[14:50:40.505] INFO: enter test to run
[14:51:58.465] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:51:58.465] INFO: running: xray
[14:51:58.466] INFO: ----------------------------------------------------------------------
[14:51:58.466] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:51:58.466] INFO: ----------------------------------------------------------------------
[14:51:59.430] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:52:06.693] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:52:37.357] INFO: Resuming triggers.
[14:52:44.620] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:53:16.279] INFO: Resuming triggers.
[14:53:23.540] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:53:54.908] INFO: Resuming triggers.
[14:54:02.170] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:54:33.708] INFO: Resuming triggers.
[14:54:40.969] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:55:11.226] INFO: Resuming triggers.
[14:55:18.485] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:55:48.699] INFO: Resuming triggers.
[14:55:55.954] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[14:56:26.226] INFO: Resuming triggers.
[14:56:33.481] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:57:03.796] INFO: Resuming triggers.
[14:57:11.051] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:57:41.298] INFO: Resuming triggers.
[14:57:48.554] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:58:18.684] INFO: Resuming triggers.
[14:58:25.939] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:58:56.173] INFO: Resuming triggers.
[14:59:03.430] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:59:33.698] INFO: Resuming triggers.
[14:59:40.954] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:00:11.178] INFO: Resuming triggers.
[15:00:17.169] INFO: data taking finished, elapsed time: 100 seconds.
[15:00:42.410] INFO: PixTest:: pg_setup set to default.
[15:00:42.413] INFO: PixTestXray::doPhRun() done
[15:00:42.562] INFO: enter test to run
[15:02:00.396] INFO: test: HighRate no parameter change
[15:02:00.396] INFO: running: highrate
[15:02:00.408] INFO: ----------------------------------------------------------------------
[15:02:00.408] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:02:00.408] INFO: ----------------------------------------------------------------------
[15:02:00.562] INFO: Expecting 768 events.
[15:02:01.697] INFO: 768 events read in total (419ms).
[15:02:01.697] INFO: Test took 1269ms.
[15:02:02.500] INFO: Expecting 41600 events.
[15:02:05.502] INFO: 41600 events read in total (2475ms).
[15:02:05.503] INFO: Test took 3780ms.
[15:02:05.533] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:06.269] INFO: Expecting 41600 events.
[15:02:09.380] INFO: 41600 events read in total (2584ms).
[15:02:09.380] INFO: Test took 3832ms.
[15:02:09.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:10.145] INFO: Expecting 41600 events.
[15:02:13.339] INFO: 41600 events read in total (2667ms).
[15:02:13.340] INFO: Test took 3914ms.
[15:02:13.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:14.101] INFO: Expecting 41600 events.
[15:02:17.311] INFO: 41600 events read in total (2684ms).
[15:02:17.312] INFO: Test took 3925ms.
[15:02:17.343] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:18.070] INFO: Expecting 41600 events.
[15:02:21.274] INFO: 41600 events read in total (2677ms).
[15:02:21.275] INFO: Test took 3915ms.
[15:02:21.306] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:22.036] INFO: Expecting 41600 events.
[15:02:25.234] INFO: 41600 events read in total (2671ms).
[15:02:25.235] INFO: Test took 3912ms.
[15:02:25.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:25.997] INFO: Expecting 41600 events.
[15:02:29.196] INFO: 41600 events read in total (2672ms).
[15:02:29.197] INFO: Test took 3914ms.
[15:02:29.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:29.961] INFO: Expecting 41600 events.
[15:02:33.177] INFO: 41600 events read in total (2689ms).
[15:02:33.178] INFO: Test took 3935ms.
[15:02:33.209] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:33.938] INFO: Expecting 41600 events.
[15:02:37.149] INFO: 41600 events read in total (2684ms).
[15:02:37.150] INFO: Test took 3923ms.
[15:02:37.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:37.910] INFO: Expecting 41600 events.
[15:02:41.131] INFO: 41600 events read in total (2694ms).
[15:02:41.132] INFO: Test took 3933ms.
[15:02:41.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:41.890] INFO: Expecting 41600 events.
[15:02:45.134] INFO: 41600 events read in total (2718ms).
[15:02:45.135] INFO: Test took 3952ms.
[15:02:45.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:45.892] INFO: Expecting 41600 events.
[15:02:49.112] INFO: 41600 events read in total (2693ms).
[15:02:49.113] INFO: Test took 3930ms.
[15:02:49.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:49.870] INFO: Expecting 41600 events.
[15:02:53.070] INFO: 41600 events read in total (2673ms).
[15:02:53.071] INFO: Test took 3910ms.
[15:02:53.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:53.834] INFO: Expecting 41600 events.
[15:02:57.065] INFO: 41600 events read in total (2704ms).
[15:02:57.066] INFO: Test took 3946ms.
[15:02:57.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:57.823] INFO: Expecting 41600 events.
[15:03:01.082] INFO: 41600 events read in total (2732ms).
[15:03:01.083] INFO: Test took 3969ms.
[15:03:01.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:01.837] INFO: Expecting 41600 events.
[15:03:05.067] INFO: 41600 events read in total (2704ms).
[15:03:05.068] INFO: Test took 3937ms.
[15:03:05.099] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:05.823] INFO: Expecting 41600 events.
[15:03:09.033] INFO: 41600 events read in total (2684ms).
[15:03:09.034] INFO: Test took 3918ms.
[15:03:09.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:09.792] INFO: Expecting 41600 events.
[15:03:13.122] INFO: 41600 events read in total (2803ms).
[15:03:13.123] INFO: Test took 4041ms.
[15:03:13.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:13.869] INFO: Expecting 41600 events.
[15:03:17.121] INFO: 41600 events read in total (2725ms).
[15:03:17.121] INFO: Test took 3950ms.
[15:03:17.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:17.879] INFO: Expecting 41600 events.
[15:03:21.018] INFO: 41600 events read in total (2612ms).
[15:03:21.018] INFO: Test took 3849ms.
[15:03:21.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:21.419] INFO: enter test to run
[15:03:39.475] INFO: test: HighRate no parameter change
[15:03:39.475] INFO: running: highrate
[15:03:39.477] INFO: ----------------------------------------------------------------------
[15:03:39.477] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:03:39.477] INFO: ----------------------------------------------------------------------
[15:03:40.101] INFO: Expecting 208000 events.
[15:03:51.796] INFO: 208000 events read in total (11168ms).
[15:03:51.799] INFO: Test took 12313ms.
[15:03:51.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:52.180] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[15:03:52.180] INFO: number of red-efficiency pixels: 89 49 71 107 119 124 118 79 83 90 105 84 98 65 26 36
[15:03:52.180] INFO: number of X-ray hits detected: 63444 38040 57884 91774 97319 98665 92781 63177 61163 88372 89848 77241 78566 47497 20482 23294
[15:03:52.180] 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:03:52.180] INFO: number of Vcal hits detected: 207910 207949 207929 207890 207881 207873 207829 207920 207916 207910 207894 207914 207902 207934 207974 207964
[15:03:52.180] 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 99.9 100.0 100.0 100.0 100.0 100.0
[15:03:52.180] 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 99.9 100.0 100.0 100.0 100.0 100.0
[15:03:52.180] INFO: X-ray hit rate [MHz/cm2]: 18.6 11.1 17.0 26.9 28.5 28.9 27.2 18.5 17.9 25.9 26.3 22.6 23.0 13.9 6.0 6.8
[15:03:52.181] INFO: PixTestHighRate::doXPixelAlive() done
[15:03:52.229] INFO: PixTest:: pg_setup set to default.
[15:03:52.242] INFO: enter test to run
[15:04:33.739] INFO: test: HighRate no parameter change
[15:04:33.739] INFO: running: highrate
[15:04:33.740] INFO: ----------------------------------------------------------------------
[15:04:33.740] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:04:33.740] INFO: ----------------------------------------------------------------------
[15:04:34.353] INFO: Expecting 208000 events.
[15:04:47.418] INFO: 208000 events read in total (12539ms).
[15:04:47.423] INFO: Test took 13676ms.
[15:04:47.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:47.959] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[15:04:47.959] INFO: number of red-efficiency pixels: 201 109 199 327 379 345 345 210 165 314 261 235 258 168 49 48
[15:04:47.959] INFO: number of X-ray hits detected: 123242 75126 113692 180149 189828 193929 180930 123851 119518 171091 175345 150487 153043 92758 39798 46078
[15:04:47.959] 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:47.959] INFO: number of Vcal hits detected: 207791 207884 207781 207654 207603 207623 207588 207782 207829 207667 207727 207753 207729 207828 207950 207950
[15:04:47.959] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 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:47.959] INFO: Vcal hit overall efficiency (%): 99.9 99.9 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
[15:04:47.959] INFO: X-ray hit rate [MHz/cm2]: 36.1 22.0 33.3 52.8 55.6 56.8 53.0 36.3 35.0 50.1 51.4 44.1 44.9 27.2 11.7 13.5
[15:04:47.959] INFO: PixTestHighRate::doXPixelAlive() done
[15:04:47.006] INFO: PixTest:: pg_setup set to default.
[15:04:48.025] INFO: enter test to run
[15:05:16.619] INFO: test: HighRate no parameter change
[15:05:16.619] INFO: running: highrate
[15:05:16.620] INFO: ----------------------------------------------------------------------
[15:05:16.620] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:05:16.620] INFO: ----------------------------------------------------------------------
[15:05:17.242] INFO: Expecting 208000 events.
[15:05:32.721] INFO: 208000 events read in total (14952ms).
[15:05:32.728] INFO: Test took 16098ms.
[15:05:33.125] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:33.464] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[15:05:33.464] INFO: number of red-efficiency pixels: 460 238 506 933 1058 803 928 559 418 839 676 637 679 422 113 95
[15:05:33.464] INFO: number of X-ray hits detected: 201737 122432 185457 293412 309411 315291 295124 203383 196116 280524 288017 246969 250459 151860 65362 75920
[15:05:33.464] 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:33.464] INFO: number of Vcal hits detected: 207425 207743 207358 206856 206701 207056 206839 207329 207537 207022 207227 207266 207229 207483 207881 207903
[15:05:33.464] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.4 99.6 99.5 99.7 99.8 99.6 99.7 99.7 99.7 99.8 99.9 100.0
[15:05:33.464] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.4 99.5 99.4 99.7 99.8 99.5 99.6 99.6 99.6 99.8 99.9 100.0
[15:05:33.464] INFO: X-ray hit rate [MHz/cm2]: 59.1 35.9 54.4 86.0 90.7 92.4 86.5 59.6 57.5 82.2 84.4 72.4 73.4 44.5 19.2 22.3
[15:05:33.464] INFO: PixTestHighRate::doXPixelAlive() done
[15:05:33.509] INFO: PixTest:: pg_setup set to default.
[15:05:33.523] INFO: enter test to run
[15:07:07.754] INFO: test: exit no parameter change
[15:07:08.188] QUIET: Connection to board 32 closed.
[15:07:08.189] INFO: pXar: this is the end, my friend