[17:27:07.040] INFO: *** Welcome to pxar ***
[17:27:07.040] INFO: *** Today: 2016/06/15
[17:27:07.060] INFO: *** Version: v1.9.0-814-g7497
[17:27:07.060] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//dacParameters35_C15.dat
[17:27:07.082] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:27:07.082] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//defaultMaskFile.dat
[17:27:07.082] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C15.dat
[17:27:07.173] INFO: clk: 4
[17:27:07.173] INFO: ctr: 4
[17:27:07.173] INFO: sda: 19
[17:27:07.173] INFO: tin: 9
[17:27:07.173] INFO: level: 15
[17:27:07.173] INFO: triggerdelay: 0
[17:27:07.173] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:27:07.173] INFO: Log level: INFO
[17:27:07.192] QUIET: Connection to board DTB_WREKRL opened.
[17:27:07.195] 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:
------------------------------------------------------
[17:27:07.198] INFO: RPC call hashes of host and DTB match: 398089610
[17:27:08.732] INFO: DUT info:
[17:27:08.732] INFO: The DUT currently contains the following objects:
[17:27:08.732] INFO: 2 TBM Cores tbm08c (2 ON)
[17:27:08.732] INFO: TBM Core alpha (0): 7 registers set
[17:27:08.732] INFO: TBM Core beta (1): 7 registers set
[17:27:08.732] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:27:08.732] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.732] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:08.733] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:27:09.136] INFO: enter 'restricted' command line mode
[17:27:09.136] INFO: enter test to run
[17:27:11.675] INFO: test: PixelAlive no parameter change
[17:27:11.675] INFO: running: pixelalive
[17:27:11.684] INFO: ----------------------------------------------------------------------
[17:27:11.684] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:27:11.685] INFO: ----------------------------------------------------------------------
[17:27:12.004] INFO: Expecting 41600 events.
[17:27:16.332] INFO: 41600 events read in total (3609ms).
[17:27:16.497] INFO: Test took 4809ms.
[17:27:16.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:16.772] INFO: PixTestAlive::aliveTest() done
[17:27:16.772] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:27:16.800] INFO: enter test to run
[17:28:28.731] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:28:28.731] INFO: running: highrate
[17:28:28.731] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:28:28.962] INFO: ----------------------------------------------------------------------
[17:28:28.962] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:28:28.962] INFO: ----------------------------------------------------------------------
[17:28:28.962] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:28:28.962] INFO: edge/corner pixel THR is adjusted
[17:28:28.962] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:28:29.921] INFO: Collecting data for 5 seconds...
[17:28:34.936] INFO: Done with hot pixel readout
[17:28:46.492] INFO: PixTest:: pg_setup set to default.
[17:28:46.493] INFO: 17 hot pixels found in step 0
[17:28:47.480] INFO: Collecting data for 5 seconds...
[17:28:52.495] INFO: Done with hot pixel readout
[17:29:04.041] INFO: PixTest:: pg_setup set to default.
[17:29:04.041] INFO: 18 hot pixels found in step 1
[17:29:05.031] INFO: Collecting data for 5 seconds...
[17:29:10.047] INFO: Done with hot pixel readout
[17:29:21.614] INFO: PixTest:: pg_setup set to default.
[17:29:21.615] INFO: 16 hot pixels found in step 2
[17:29:22.606] INFO: Collecting data for 5 seconds...
[17:29:27.621] INFO: Done with hot pixel readout
[17:29:39.201] INFO: PixTest:: pg_setup set to default.

[17:29:39.201] INFO: 17 hot pixels found in step 3
[17:29:40.191] INFO: Collecting data for 5 seconds...
[17:29:45.208] INFO: Done with hot pixel readout
[17:29:56.804] INFO: PixTest:: pg_setup set to default.

[17:29:56.805] INFO: 13 hot pixels found in step 4
[17:29:57.796] INFO: Collecting data for 5 seconds...
[17:30:02.811] INFO: Done with hot pixel readout
[17:30:14.407] INFO: PixTest:: pg_setup set to default.
[17:30:14.408] INFO: 16 hot pixels found in step 5
[17:30:15.400] INFO: Collecting data for 5 seconds...
[17:30:20.416] INFO: Done with hot pixel readout
[17:30:31.979] INFO: PixTest:: pg_setup set to default.
[17:30:31.980] INFO: 6 hot pixels found in step 6
[17:30:32.971] INFO: Collecting data for 5 seconds...
[17:30:37.986] INFO: Done with hot pixel readout
[17:30:49.557] INFO: PixTest:: pg_setup set to default.
[17:30:49.558] INFO: 8 hot pixels found in step 7
[17:30:50.549] INFO: Collecting data for 5 seconds...
[17:30:55.564] INFO: Done with hot pixel readout
[17:31:07.185] INFO: PixTest:: pg_setup set to default.

[17:31:07.186] INFO: 5 hot pixels found in step 8
[17:31:08.177] INFO: Collecting data for 5 seconds...
[17:31:13.192] INFO: Done with hot pixel readout
[17:31:24.780] INFO: PixTest:: pg_setup set to default.

[17:31:24.781] INFO: 8 hot pixels found in step 9
[17:31:25.772] INFO: Collecting data for 5 seconds...
[17:31:30.787] INFO: Done with hot pixel readout
[17:31:42.335] INFO: PixTest:: pg_setup set to default.
[17:31:42.336] INFO: 6 hot pixels found in step 10
[17:31:43.326] INFO: Collecting data for 5 seconds...
[17:31:48.341] INFO: Done with hot pixel readout
[17:31:59.929] INFO: PixTest:: pg_setup set to default.

[17:31:59.930] INFO: 6 hot pixels found in step 11
[17:32:00.918] INFO: Collecting data for 5 seconds...
[17:32:05.933] INFO: Done with hot pixel readout
[17:32:17.481] INFO: PixTest:: pg_setup set to default.

[17:32:17.482] INFO: 5 hot pixels found in step 12
[17:32:18.472] INFO: Collecting data for 5 seconds...
[17:32:23.488] INFO: Done with hot pixel readout
[17:32:35.136] INFO: PixTest:: pg_setup set to default.


[17:32:35.137] INFO: 7 hot pixels found in step 13
[17:32:36.126] INFO: Collecting data for 5 seconds...
[17:32:41.142] INFO: Done with hot pixel readout
[17:32:52.728] INFO: PixTest:: pg_setup set to default.
[17:32:52.729] INFO: 7 hot pixels found in step 14
[17:32:52.762] INFO: 7 hot pixels could not be trimmed and have been masked.
[17:32:52.766] INFO: PixTest::trimHotPixels() done
[17:32:52.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C0.dat
[17:32:52.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C1.dat
[17:32:52.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C2.dat
[17:32:52.783] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C3.dat
[17:32:52.788] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C4.dat
[17:32:52.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C5.dat
[17:32:52.799] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C6.dat
[17:32:52.804] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C7.dat
[17:32:52.809] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C8.dat
[17:32:52.815] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C9.dat
[17:32:52.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C10.dat
[17:32:52.825] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C11.dat
[17:32:52.830] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C12.dat
[17:32:52.835] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C13.dat
[17:32:52.841] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C14.dat
[17:32:52.846] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C15.dat
[17:32:52.851] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//defaultMaskFile.dat
[17:32:52.861] INFO: enter test to run
[17:36:28.624] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:36:28.624] INFO: running: highrate
[17:36:28.628] INFO: ----------------------------------------------------------------------
[17:36:28.628] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:36:28.628] INFO: ----------------------------------------------------------------------
[17:36:28.628] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:36:28.628] INFO: edge/corner pixel THR is adjusted
[17:36:28.628] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:36:29.587] INFO: Collecting data for 1 seconds...
[17:36:30.590] INFO: Done with hot pixel readout
[17:36:34.471] INFO: PixTest:: pg_setup set to default.
[17:36:34.472] INFO: 0 hot pixels found in step 0
[17:36:34.477] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:36:34.572] INFO: PixTest::trimHotPixels() done
[17:36:34.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C0.dat
[17:36:34.584] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C1.dat
[17:36:34.590] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C2.dat
[17:36:34.596] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C3.dat
[17:36:34.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C4.dat
[17:36:34.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C5.dat
[17:36:34.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C6.dat
[17:36:34.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C7.dat
[17:36:34.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C8.dat
[17:36:34.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C9.dat
[17:36:34.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C10.dat
[17:36:34.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C11.dat
[17:36:34.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C12.dat
[17:36:34.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C13.dat
[17:36:34.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C14.dat
[17:36:34.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C15.dat
[17:36:34.663] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-34_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//defaultMaskFile.dat
[17:36:34.672] INFO: enter test to run
[17:37:46.847] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:37:46.847] INFO: running: xray
[17:37:46.848] INFO: ----------------------------------------------------------------------
[17:37:46.848] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:37:46.848] INFO: ----------------------------------------------------------------------
[17:37:47.811] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:37:59.425] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:38:28.786] INFO: Resuming triggers.
[17:38:40.405] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[17:39:09.749] INFO: Resuming triggers.
[17:39:21.369] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:39:50.765] INFO: Resuming triggers.
[17:40:02.384] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[17:40:31.737] INFO: Resuming triggers.
[17:40:43.354] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[17:41:12.528] INFO: Resuming triggers.
[17:41:24.140] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:41:53.422] INFO: Resuming triggers.
[17:42:05.037] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:42:34.340] INFO: Resuming triggers.
[17:42:45.959] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:43:15.244] INFO: Resuming triggers.
[17:43:22.617] INFO: data taking finished, elapsed time: 100 seconds.
[17:43:41.474] INFO: PixTest:: pg_setup set to default.
[17:43:41.477] INFO: PixTestXray::doPhRun() done
[17:43:41.613] INFO: enter test to run
[17:47:28.075] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:47:28.075] INFO: running: xray
[17:47:28.076] INFO: ----------------------------------------------------------------------
[17:47:28.076] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:47:28.076] INFO: ----------------------------------------------------------------------
[17:47:29.040] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:47:35.992] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:48:06.055] INFO: Resuming triggers.
[17:48:13.005] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[17:48:43.118] INFO: Resuming triggers.
[17:48:50.069] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[17:49:20.150] INFO: Resuming triggers.
[17:49:27.102] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[17:49:57.148] INFO: Resuming triggers.
[17:50:04.104] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:50:34.191] INFO: Resuming triggers.
[17:50:41.146] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[17:51:11.213] INFO: Resuming triggers.
[17:51:18.165] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[17:51:48.218] INFO: Resuming triggers.
[17:51:55.169] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[17:52:25.243] INFO: Resuming triggers.
[17:52:32.193] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[17:53:02.232] INFO: Resuming triggers.
[17:53:09.183] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:53:39.189] INFO: Resuming triggers.
[17:53:46.142] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[17:54:16.190] INFO: Resuming triggers.
[17:54:23.145] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[17:54:53.254] INFO: Resuming triggers.
[17:55:00.208] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[17:55:30.299] INFO: Resuming triggers.
[17:55:37.253] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[17:56:07.256] INFO: Resuming triggers.
[17:56:10.227] INFO: data taking finished, elapsed time: 100 seconds.
[17:56:23.361] INFO: PixTest:: pg_setup set to default.
[17:56:23.364] INFO: PixTestXray::doPhRun() done
[17:56:23.514] INFO: enter test to run
[17:56:52.231] INFO: test: HighRate no parameter change
[17:56:52.231] INFO: running: highrate
[17:56:52.233] INFO: ----------------------------------------------------------------------
[17:56:52.233] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:56:52.233] INFO: ----------------------------------------------------------------------
[17:56:52.375] INFO: Expecting 768 events.
[17:56:53.509] INFO: 768 events read in total (418ms).
[17:56:53.510] INFO: Test took 1270ms.
[17:56:54.313] INFO: Expecting 41600 events.
[17:56:57.393] INFO: 41600 events read in total (2553ms).
[17:56:57.394] INFO: Test took 3877ms.
[17:56:57.425] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:56:58.158] INFO: Expecting 41600 events.
[17:57:01.353] INFO: 41600 events read in total (2668ms).
[17:57:01.354] INFO: Test took 3912ms.
[17:57:01.385] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:02.114] INFO: Expecting 41600 events.
[17:57:05.317] INFO: 41600 events read in total (2676ms).
[17:57:05.318] INFO: Test took 3917ms.
[17:57:05.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:06.080] INFO: Expecting 41600 events.
[17:57:09.307] INFO: 41600 events read in total (2700ms).
[17:57:09.308] INFO: Test took 3940ms.
[17:57:09.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:10.065] INFO: Expecting 41600 events.
[17:57:13.273] INFO: 41600 events read in total (2681ms).
[17:57:13.274] INFO: Test took 3917ms.
[17:57:13.305] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:14.036] INFO: Expecting 41600 events.
[17:57:17.252] INFO: 41600 events read in total (2689ms).
[17:57:17.253] INFO: Test took 3931ms.
[17:57:17.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:18.010] INFO: Expecting 41600 events.
[17:57:21.226] INFO: 41600 events read in total (2689ms).
[17:57:21.227] INFO: Test took 3925ms.
[17:57:21.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:21.987] INFO: Expecting 41600 events.
[17:57:25.196] INFO: 41600 events read in total (2682ms).
[17:57:25.197] INFO: Test took 3920ms.
[17:57:25.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:25.953] INFO: Expecting 41600 events.
[17:57:29.170] INFO: 41600 events read in total (2690ms).
[17:57:29.171] INFO: Test took 3924ms.
[17:57:29.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:29.932] INFO: Expecting 41600 events.
[17:57:33.152] INFO: 41600 events read in total (2693ms).
[17:57:33.153] INFO: Test took 3933ms.
[17:57:33.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:33.910] INFO: Expecting 41600 events.
[17:57:37.126] INFO: 41600 events read in total (2690ms).
[17:57:37.127] INFO: Test took 3925ms.
[17:57:37.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:37.886] INFO: Expecting 41600 events.
[17:57:41.121] INFO: 41600 events read in total (2709ms).
[17:57:41.122] INFO: Test took 3945ms.
[17:57:41.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:41.880] INFO: Expecting 41600 events.
[17:57:45.105] INFO: 41600 events read in total (2699ms).
[17:57:45.106] INFO: Test took 3934ms.
[17:57:45.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:45.865] INFO: Expecting 41600 events.
[17:57:49.076] INFO: 41600 events read in total (2684ms).
[17:57:49.077] INFO: Test took 3922ms.
[17:57:49.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:49.835] INFO: Expecting 41600 events.
[17:57:53.040] INFO: 41600 events read in total (2678ms).
[17:57:53.041] INFO: Test took 3913ms.
[17:57:53.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:53.802] INFO: Expecting 41600 events.
[17:57:57.036] INFO: 41600 events read in total (2707ms).
[17:57:57.037] INFO: Test took 3946ms.
[17:57:57.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:57.798] INFO: Expecting 41600 events.
[17:58:01.009] INFO: 41600 events read in total (2684ms).
[17:58:01.010] INFO: Test took 3923ms.
[17:58:01.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:01.772] INFO: Expecting 41600 events.
[17:58:04.986] INFO: 41600 events read in total (2687ms).
[17:58:04.987] INFO: Test took 3928ms.
[17:58:05.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:05.742] INFO: Expecting 41600 events.
[17:58:08.926] INFO: 41600 events read in total (2657ms).
[17:58:08.927] INFO: Test took 3889ms.
[17:58:08.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:09.687] INFO: Expecting 41600 events.
[17:58:12.712] INFO: 41600 events read in total (2498ms).
[17:58:12.713] INFO: Test took 3738ms.
[17:58:12.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:13.115] INFO: enter test to run
[17:58:25.311] INFO: test: HighRate no parameter change
[17:58:25.311] INFO: running: highrate
[17:58:25.312] INFO: ----------------------------------------------------------------------
[17:58:25.312] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:58:25.312] INFO: ----------------------------------------------------------------------
[17:58:25.927] INFO: Expecting 208000 events.
[17:58:37.704] INFO: 208000 events read in total (11250ms).
[17:58:37.707] INFO: Test took 12386ms.
[17:58:37.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:38.095] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:58:38.095] INFO: number of red-efficiency pixels: 51 31 101 125 121 120 127 125 71 110 105 86 83 35 20 23
[17:58:38.095] INFO: number of X-ray hits detected: 58114 38928 66335 97723 108713 115552 115154 84246 70688 88002 81770 73678 77235 45277 20944 23235
[17:58:38.095] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:58:38.095] INFO: number of Vcal hits detected: 207949 207969 207898 207871 207859 207878 207862 207872 207927 207886 207894 207912 207916 207965 207980 207977
[17:58:38.095] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[17:58:38.095] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[17:58:38.095] INFO: X-ray hit rate [MHz/cm2]: 17.0 11.4 19.4 28.6 31.9 33.9 33.8 24.7 20.7 25.8 24.0 21.6 22.6 13.3 6.1 6.8
[17:58:38.095] INFO: PixTestHighRate::doXPixelAlive() done
[17:58:38.145] INFO: PixTest:: pg_setup set to default.
[17:58:38.156] INFO: enter test to run
[17:58:54.582] INFO: test: HighRate no parameter change
[17:58:54.583] INFO: running: highrate
[17:58:54.584] INFO: ----------------------------------------------------------------------
[17:58:54.584] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:58:54.584] INFO: ----------------------------------------------------------------------
[17:58:55.203] INFO: Expecting 208000 events.
[17:59:08.611] INFO: 208000 events read in total (12881ms).
[17:59:08.616] INFO: Test took 14021ms.
[17:59:08.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:09.189] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:59:09.189] INFO: number of red-efficiency pixels: 173 121 299 403 378 428 442 364 215 360 288 217 224 148 45 51
[17:59:09.189] INFO: number of X-ray hits detected: 120675 81670 138245 203754 227111 239222 240109 175507 147243 182623 171722 152736 161566 94437 44345 49011
[17:59:09.189] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:59:09.189] INFO: number of Vcal hits detected: 207819 207873 207667 207573 207566 207531 207480 207610 207775 207617 207698 207775 207759 207843 207954 207949
[17:59:09.189] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[17:59:09.189] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[17:59:09.189] INFO: X-ray hit rate [MHz/cm2]: 35.4 23.9 40.5 59.7 66.6 70.1 70.4 51.4 43.2 53.5 50.3 44.8 47.4 27.7 13.0 14.4
[17:59:09.189] INFO: PixTestHighRate::doXPixelAlive() done
[17:59:09.241] INFO: PixTest:: pg_setup set to default.
[17:59:09.256] INFO: enter test to run
[17:59:32.030] INFO: test: HighRate no parameter change
[17:59:32.030] INFO: running: highrate
[17:59:32.031] INFO: ----------------------------------------------------------------------
[17:59:32.032] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:59:32.032] INFO: ----------------------------------------------------------------------
[17:59:32.648] INFO: Expecting 208000 events.
[17:59:47.749] INFO: 208000 events read in total (14574ms).
[17:59:47.756] INFO: Test took 15715ms.
[17:59:48.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:48.498] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:59:48.498] INFO: number of red-efficiency pixels: 355 230 662 944 894 1033 1015 793 387 823 683 441 442 298 94 88
[17:59:48.498] INFO: number of X-ray hits detected: 180566 123235 207831 304829 339006 358952 358485 263648 220893 274196 256831 229198 242722 142127 65846 73820
[17:59:48.498] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:59:48.498] INFO: number of Vcal hits detected: 207601 207756 207149 206859 206888 206714 206701 206975 207580 207027 207237 207527 207516 207663 207902 207909
[17:59:48.498] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.5 99.4 99.4 99.6 99.8 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[17:59:48.498] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.5 99.5 99.4 99.4 99.5 99.8 99.5 99.6 99.8 99.8 99.8 100.0 100.0
[17:59:48.498] INFO: X-ray hit rate [MHz/cm2]: 52.9 36.1 60.9 89.3 99.4 105.2 105.1 77.3 64.7 80.4 75.3 67.2 71.1 41.7 19.3 21.6
[17:59:48.498] INFO: PixTestHighRate::doXPixelAlive() done
[17:59:48.549] INFO: PixTest:: pg_setup set to default.
[17:59:48.561] INFO: enter test to run
[17:59:53.054] INFO: test: exit no parameter change
[17:59:53.355] QUIET: Connection to board 33 closed.
[17:59:53.356] INFO: pXar: this is the end, my friend