[10:23:38.821] INFO: *** Welcome to pxar ***
[10:23:38.821] INFO: *** Today: 2016/04/04
[10:23:38.842] INFO: *** Version: v1.9.0-793-ge521-dirty
[10:23:38.842] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//dacParameters35_C15.dat
[10:23:38.868] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:23:38.869] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//defaultMaskFile.dat
[10:23:38.869] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C15.dat
[10:23:38.938] INFO: clk: 4
[10:23:38.938] INFO: ctr: 4
[10:23:38.938] INFO: sda: 19
[10:23:38.938] INFO: tin: 9
[10:23:38.938] INFO: level: 15
[10:23:38.938] INFO: triggerdelay: 0
[10:23:38.938] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[10:23:38.938] INFO: Log level: INFO
[10:23:38.956] QUIET: Connection to board DTB_WREKRL opened.
[10:23:38.959] 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:
------------------------------------------------------
[10:23:38.962] INFO: RPC call hashes of host and DTB match: 398089610
[10:23:40.495] INFO: DUT info:
[10:23:40.495] INFO: The DUT currently contains the following objects:
[10:23:40.495] INFO: 2 TBM Cores tbm08c (2 ON)
[10:23:40.495] INFO: TBM Core alpha (0): 7 registers set
[10:23:40.495] INFO: TBM Core beta (1): 7 registers set
[10:23:40.495] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:23:40.495] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.495] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.495] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.495] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.495] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.495] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.496] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:40.899] INFO: enter 'restricted' command line mode
[10:23:40.899] INFO: enter test to run
[10:24:11.131] INFO: test: PixelAlive no parameter change
[10:24:11.131] INFO: running: pixelalive
[10:24:11.141] INFO: ----------------------------------------------------------------------
[10:24:11.141] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:24:11.141] INFO: ----------------------------------------------------------------------
[10:24:11.460] INFO: Expecting 41600 events.
[10:24:15.784] INFO: 41600 events read in total (3605ms).
[10:24:15.949] INFO: Test took 4804ms.
[10:24:15.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:16.221] INFO: PixTestAlive::aliveTest() done
[10:24:16.221] INFO: number of dead pixels (per ROC): 0 0 2 3 0 2 0 0 0 0 0 1 0 0 0 0
[10:24:16.251] INFO: enter test to run
[10:24:43.515] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:24:43.515] INFO: running: highrate
[10:24:43.515] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:24:43.780] INFO: ----------------------------------------------------------------------
[10:24:43.780] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:24:43.780] INFO: ----------------------------------------------------------------------
[10:24:43.780] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:24:43.780] INFO: edge/corner pixel THR is adjusted
[10:24:43.780] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:24:44.738] INFO: Collecting data for 5 seconds...
[10:24:49.755] INFO: Done with hot pixel readout
[10:25:01.584] INFO: PixTest:: pg_setup set to default.
[10:25:01.584] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:25:01.585] INFO: 11 hot pixels found in step 0
[10:25:02.575] INFO: Collecting data for 5 seconds...
[10:25:07.592] INFO: Done with hot pixel readout
[10:25:19.367] INFO: PixTest:: pg_setup set to default.
[10:25:19.368] INFO: 11 hot pixels found in step 1
[10:25:20.360] INFO: Collecting data for 5 seconds...
[10:25:25.378] INFO: Done with hot pixel readout
[10:25:37.145] INFO: PixTest:: pg_setup set to default.
[10:25:37.145] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:25:37.145] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:25:37.145] INFO: 13 hot pixels found in step 2
[10:25:38.138] INFO: Collecting data for 5 seconds...
[10:25:43.155] INFO: Done with hot pixel readout
[10:25:54.945] INFO: PixTest:: pg_setup set to default.
[10:25:54.946] INFO: 4 hot pixels found in step 3
[10:25:55.939] INFO: Collecting data for 5 seconds...
[10:26:00.949] INFO: Done with hot pixel readout
[10:26:09.535] INFO: PixTest:: pg_setup set to default.
[10:26:09.536] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:26:09.536] INFO: 10 hot pixels found in step 4
[10:26:10.526] INFO: Collecting data for 5 seconds...
[10:26:15.543] INFO: Done with hot pixel readout
[10:26:27.276] INFO: PixTest:: pg_setup set to default.
[10:26:27.276] INFO: 7 hot pixels found in step 5
[10:26:28.267] INFO: Collecting data for 5 seconds...
[10:26:33.284] INFO: Done with hot pixel readout
[10:26:43.891] INFO: PixTest:: pg_setup set to default.
[10:26:43.892] INFO: 9 hot pixels found in step 6
[10:26:44.882] INFO: Collecting data for 5 seconds...
[10:26:49.892] INFO: Done with hot pixel readout
[10:26:59.785] INFO: PixTest:: pg_setup set to default.
[10:26:59.786] INFO: 6 hot pixels found in step 7
[10:27:00.778] INFO: Collecting data for 5 seconds...
[10:27:05.796] INFO: Done with hot pixel readout
[10:27:17.224] INFO: PixTest:: pg_setup set to default.
[10:27:17.224] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:27:17.224] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:27:17.225] INFO: 10 hot pixels found in step 8
[10:27:18.217] INFO: Collecting data for 5 seconds...
[10:27:23.234] INFO: Done with hot pixel readout
[10:27:34.897] INFO: PixTest:: pg_setup set to default.
[10:27:34.898] INFO: 6 hot pixels found in step 9
[10:27:35.889] INFO: Collecting data for 5 seconds...
[10:27:40.906] INFO: Done with hot pixel readout
[10:27:52.665] INFO: PixTest:: pg_setup set to default.
[10:27:52.666] INFO: 7 hot pixels found in step 10
[10:27:53.657] INFO: Collecting data for 5 seconds...
[10:27:58.674] INFO: Done with hot pixel readout
[10:28:10.404] INFO: PixTest:: pg_setup set to default.
[10:28:10.405] INFO: 4 hot pixels found in step 11
[10:28:11.395] INFO: Collecting data for 5 seconds...
[10:28:16.411] INFO: Done with hot pixel readout
[10:28:28.130] INFO: PixTest:: pg_setup set to default.
[10:28:28.130] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:28:28.130] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:28:28.131] INFO: 5 hot pixels found in step 12
[10:28:29.123] INFO: Collecting data for 5 seconds...
[10:28:34.141] INFO: Done with hot pixel readout
[10:28:45.949] INFO: PixTest:: pg_setup set to default.
[10:28:45.950] INFO: 9 hot pixels found in step 13
[10:28:46.942] INFO: Collecting data for 5 seconds...
[10:28:51.960] INFO: Done with hot pixel readout
[10:29:03.780] INFO: PixTest:: pg_setup set to default.
[10:29:03.781] INFO: 7 hot pixels found in step 14
[10:29:03.816] INFO: 7 hot pixels could not be trimmed and have been masked.
[10:29:03.820] INFO: PixTest::trimHotPixels() done
[10:29:03.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C0.dat
[10:29:03.826] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C1.dat
[10:29:03.832] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C2.dat
[10:29:03.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C3.dat
[10:29:03.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C4.dat
[10:29:03.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C5.dat
[10:29:03.854] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C6.dat
[10:29:03.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C7.dat
[10:29:03.865] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C8.dat
[10:29:03.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C9.dat
[10:29:03.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C10.dat
[10:29:03.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C11.dat
[10:29:03.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C12.dat
[10:29:03.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C13.dat
[10:29:03.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C14.dat
[10:29:03.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C15.dat
[10:29:03.908] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//defaultMaskFile.dat
[10:29:03.918] INFO: enter test to run
[10:30:29.673] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:30:29.673] INFO: running: highrate
[10:30:29.677] INFO: ----------------------------------------------------------------------
[10:30:29.677] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:30:29.677] INFO: ----------------------------------------------------------------------
[10:30:29.677] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:30:29.677] INFO: edge/corner pixel THR is adjusted
[10:30:29.677] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:30:30.636] INFO: Collecting data for 1 seconds...
[10:30:31.640] INFO: Done with hot pixel readout
[10:30:35.772] INFO: PixTest:: pg_setup set to default.
[10:30:35.773] INFO: 0 hot pixels found in step 0
[10:30:35.778] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:30:35.867] INFO: PixTest::trimHotPixels() done
[10:30:35.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C0.dat
[10:30:35.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C1.dat
[10:30:35.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C2.dat
[10:30:35.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C3.dat
[10:30:35.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C4.dat
[10:30:35.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C5.dat
[10:30:35.902] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C6.dat
[10:30:35.907] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C7.dat
[10:30:35.912] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C8.dat
[10:30:35.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C9.dat
[10:30:35.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C10.dat
[10:30:35.928] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C11.dat
[10:30:35.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C12.dat
[10:30:35.939] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C13.dat
[10:30:35.944] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C14.dat
[10:30:35.949] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//trimParameters35_C15.dat
[10:30:35.954] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-1-11_FPIXTest-17C-FNAL-160401-1148_2016-04-01_11h48m_1459529315/000_FPIXTest_p17//defaultMaskFile.dat
[10:30:35.964] INFO: enter test to run
[10:31:00.888] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:31:00.888] INFO: running: xray
[10:31:00.890] INFO: ----------------------------------------------------------------------
[10:31:00.890] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:31:00.890] INFO: ----------------------------------------------------------------------
[10:31:01.853] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:31:13.225] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:31:42.559] INFO: Resuming triggers.
[10:31:53.932] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:32:23.429] INFO: Resuming triggers.
[10:32:34.803] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:33:04.249] INFO: Resuming triggers.
[10:33:15.624] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[10:33:44.972] INFO: Resuming triggers.
[10:33:56.346] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[10:34:25.779] INFO: Resuming triggers.
[10:34:37.150] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[10:35:06.524] INFO: Resuming triggers.
[10:35:17.894] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:35:47.276] INFO: Resuming triggers.
[10:35:58.647] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[10:36:28.062] INFO: Resuming triggers.
[10:36:37.412] INFO: data taking finished, elapsed time: 100 seconds.
[10:36:58.621] INFO: PixTest:: pg_setup set to default.
[10:36:58.624] INFO: PixTestXray::doPhRun() done
[10:36:58.759] INFO: enter test to run
[10:37:30.998] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:37:30.998] INFO: running: xray
[10:37:30.999] INFO: ----------------------------------------------------------------------
[10:37:30.999] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:37:30.999] INFO: ----------------------------------------------------------------------
[10:37:31.963] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:37:38.366] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:38:08.443] INFO: Resuming triggers.
[10:38:14.848] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:38:44.900] INFO: Resuming triggers.
[10:38:51.301] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:39:21.421] INFO: Resuming triggers.
[10:39:27.827] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[10:39:58.534] INFO: Resuming triggers.
[10:40:04.939] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[10:40:34.717] INFO: Resuming triggers.
[10:40:41.123] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[10:41:10.947] INFO: Resuming triggers.
[10:41:17.347] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:41:47.438] INFO: Resuming triggers.
[10:41:53.840] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[10:42:23.651] INFO: Resuming triggers.
[10:42:30.052] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:42:59.747] INFO: Resuming triggers.
[10:43:06.148] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:43:36.037] INFO: Resuming triggers.
[10:43:42.441] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:44:12.250] INFO: Resuming triggers.
[10:44:18.653] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[10:44:48.519] INFO: Resuming triggers.
[10:44:54.920] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:45:25.201] INFO: Resuming triggers.
[10:45:31.598] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[10:46:01.746] INFO: Resuming triggers.
[10:46:08.149] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[10:46:38.241] INFO: Resuming triggers.
[10:46:42.524] INFO: data taking finished, elapsed time: 100 seconds.
[10:47:01.137] INFO: PixTest:: pg_setup set to default.
[10:47:01.140] INFO: PixTestXray::doPhRun() done
[10:47:01.296] INFO: enter test to run
[10:48:42.497] INFO: test: HighRate no parameter change
[10:48:42.497] INFO: running: highrate
[10:48:42.498] INFO: ----------------------------------------------------------------------
[10:48:42.498] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:48:42.498] INFO: ----------------------------------------------------------------------
[10:48:42.638] INFO: Expecting 768 events.
[10:48:43.772] INFO: 768 events read in total (418ms).
[10:48:43.772] INFO: Test took 1268ms.
[10:48:44.575] INFO: Expecting 41600 events.
[10:48:47.619] INFO: 41600 events read in total (2517ms).
[10:48:47.621] INFO: Test took 3841ms.
[10:48:47.655] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:48.384] INFO: Expecting 41600 events.
[10:48:51.565] INFO: 41600 events read in total (2654ms).
[10:48:51.566] INFO: Test took 3893ms.
[10:48:51.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:52.322] INFO: Expecting 41600 events.
[10:48:55.550] INFO: 41600 events read in total (2701ms).
[10:48:55.551] INFO: Test took 3932ms.
[10:48:55.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:56.308] INFO: Expecting 41600 events.
[10:48:59.558] INFO: 41600 events read in total (2723ms).
[10:48:59.559] INFO: Test took 3954ms.
[10:48:59.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:00.313] INFO: Expecting 41600 events.
[10:49:03.545] INFO: 41600 events read in total (2705ms).
[10:49:03.546] INFO: Test took 3933ms.
[10:49:03.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:04.305] INFO: Expecting 41600 events.
[10:49:07.550] INFO: 41600 events read in total (2719ms).
[10:49:07.551] INFO: Test took 3952ms.
[10:49:07.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:08.305] INFO: Expecting 41600 events.
[10:49:11.561] INFO: 41600 events read in total (2730ms).
[10:49:11.562] INFO: Test took 3954ms.
[10:49:11.596] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:12.319] INFO: Expecting 41600 events.
[10:49:15.521] INFO: 41600 events read in total (2675ms).
[10:49:15.522] INFO: Test took 3909ms.
[10:49:15.558] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:16.280] INFO: Expecting 41600 events.
[10:49:19.495] INFO: 41600 events read in total (2688ms).
[10:49:19.496] INFO: Test took 3919ms.
[10:49:19.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:20.257] INFO: Expecting 41600 events.
[10:49:23.511] INFO: 41600 events read in total (2727ms).
[10:49:23.512] INFO: Test took 3963ms.
[10:49:23.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:24.267] INFO: Expecting 41600 events.
[10:49:27.519] INFO: 41600 events read in total (2725ms).
[10:49:27.520] INFO: Test took 3956ms.
[10:49:27.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:28.276] INFO: Expecting 41600 events.
[10:49:31.503] INFO: 41600 events read in total (2700ms).
[10:49:31.504] INFO: Test took 3930ms.
[10:49:31.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:32.259] INFO: Expecting 41600 events.
[10:49:35.499] INFO: 41600 events read in total (2713ms).
[10:49:35.500] INFO: Test took 3942ms.
[10:49:35.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:36.257] INFO: Expecting 41600 events.
[10:49:39.511] INFO: 41600 events read in total (2727ms).
[10:49:39.512] INFO: Test took 3960ms.
[10:49:39.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:40.270] INFO: Expecting 41600 events.
[10:49:43.506] INFO: 41600 events read in total (2709ms).
[10:49:43.506] INFO: Test took 3940ms.
[10:49:43.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:44.264] INFO: Expecting 41600 events.
[10:49:47.534] INFO: 41600 events read in total (2744ms).
[10:49:47.535] INFO: Test took 3976ms.
[10:49:47.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:48.291] INFO: Expecting 41600 events.
[10:49:51.521] INFO: 41600 events read in total (2703ms).
[10:49:51.521] INFO: Test took 3933ms.
[10:49:51.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:52.278] INFO: Expecting 41600 events.
[10:49:55.518] INFO: 41600 events read in total (2713ms).
[10:49:55.519] INFO: Test took 3944ms.
[10:49:55.552] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:56.279] INFO: Expecting 41600 events.
[10:49:59.536] INFO: 41600 events read in total (2730ms).
[10:49:59.537] INFO: Test took 3966ms.
[10:49:59.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:00.294] INFO: Expecting 41600 events.
[10:50:03.425] INFO: 41600 events read in total (2604ms).
[10:50:03.426] INFO: Test took 3834ms.
[10:50:03.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:03.827] INFO: enter test to run
[10:50:29.352] INFO: test: HighRate no parameter change
[10:50:29.352] INFO: running: highrate
[10:50:29.353] INFO: ----------------------------------------------------------------------
[10:50:29.353] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:50:29.353] INFO: ----------------------------------------------------------------------
[10:50:29.974] INFO: Expecting 208000 events.
[10:50:41.871] INFO: 208000 events read in total (11370ms).
[10:50:41.874] INFO: Test took 12510ms.
[10:50:42.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:42.271] INFO: number of dead pixels (per ROC): 0 0 1 3 0 2 0 0 0 0 0 1 0 0 0 0
[10:50:42.271] INFO: number of red-efficiency pixels: 64 50 113 157 136 171 123 94 107 109 120 88 104 60 23 21
[10:50:42.271] INFO: number of X-ray hits detected: 63633 43851 70357 112920 114189 123450 114512 85069 82600 100327 98016 85360 89110 53181 22668 27644
[10:50:42.271] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:50:42.271] INFO: number of Vcal hits detected: 207934 207949 207831 207694 207861 207725 207874 207902 207893 207888 207879 207861 207891 207937 207977 207979
[10:50:42.271] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:50:42.271] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:50:42.271] INFO: X-ray hit rate [MHz/cm2]: 18.7 12.9 20.6 33.1 33.5 36.2 33.6 24.9 24.2 29.4 28.7 25.0 26.1 15.6 6.6 8.1
[10:50:42.271] INFO: PixTestHighRate::doXPixelAlive() done
[10:50:42.321] INFO: PixTest:: pg_setup set to default.
[10:50:42.333] INFO: enter test to run
[10:51:13.703] INFO: test: HighRate no parameter change
[10:51:13.704] INFO: running: highrate
[10:51:13.705] INFO: ----------------------------------------------------------------------
[10:51:13.705] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:51:13.705] INFO: ----------------------------------------------------------------------
[10:51:14.327] INFO: Expecting 208000 events.
[10:51:28.173] INFO: 208000 events read in total (13319ms).
[10:51:28.178] INFO: Test took 14463ms.
[10:51:28.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:28.801] INFO: number of dead pixels (per ROC): 0 0 1 3 0 2 0 0 0 0 0 1 0 0 0 0
[10:51:28.801] INFO: number of red-efficiency pixels: 175 168 347 571 531 590 530 321 274 339 443 384 254 188 71 67
[10:51:28.801] INFO: number of X-ray hits detected: 135278 93301 150632 239456 242487 262124 243450 182939 176792 213593 208146 181613 187659 112496 48241 57937
[10:51:28.801] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:51:28.801] INFO: number of Vcal hits detected: 207817 207821 207548 207214 207432 207244 207410 207651 207705 207640 207520 207545 207729 207806 207926 207931
[10:51:28.801] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[10:51:28.801] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.6 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[10:51:28.801] INFO: X-ray hit rate [MHz/cm2]: 39.7 27.3 44.2 70.2 71.1 76.8 71.4 53.6 51.8 62.6 61.0 53.2 55.0 33.0 14.1 17.0
[10:51:28.801] INFO: PixTestHighRate::doXPixelAlive() done
[10:51:28.850] INFO: PixTest:: pg_setup set to default.
[10:51:28.867] INFO: enter test to run
[10:52:03.175] INFO: test: HighRate no parameter change
[10:52:03.175] INFO: running: highrate
[10:52:03.176] INFO: ----------------------------------------------------------------------
[10:52:03.176] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:52:03.176] INFO: ----------------------------------------------------------------------
[10:52:03.792] INFO: Expecting 208000 events.
[10:52:19.580] INFO: 208000 events read in total (15261ms).
[10:52:19.587] INFO: Test took 16400ms.
[10:52:20.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:20.420] INFO: number of dead pixels (per ROC): 0 0 1 3 0 2 0 0 0 0 0 1 0 0 0 0
[10:52:20.421] INFO: number of red-efficiency pixels: 379 323 765 1289 1283 1349 1191 680 626 841 1038 775 606 406 103 103
[10:52:20.421] INFO: number of X-ray hits detected: 203469 141809 226538 361138 367950 397232 367541 275009 268151 323282 315868 274571 284419 170593 73992 88601
[10:52:20.421] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:52:20.421] INFO: number of Vcal hits detected: 207571 207645 206866 206195 206305 206032 206482 207164 207263 207009 206695 207019 207308 207535 207893 207897
[10:52:20.421] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.5 99.3 99.3 99.2 99.4 99.6 99.7 99.6 99.4 99.6 99.7 99.8 100.0 100.0
[10:52:20.421] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.5 99.1 99.2 99.1 99.3 99.6 99.6 99.5 99.4 99.5 99.7 99.8 99.9 100.0
[10:52:20.421] INFO: X-ray hit rate [MHz/cm2]: 59.6 41.6 66.4 105.9 107.8 116.4 107.7 80.6 78.6 94.8 92.6 80.5 83.4 50.0 21.7 26.0
[10:52:20.421] INFO: PixTestHighRate::doXPixelAlive() done
[10:52:20.467] INFO: PixTest:: pg_setup set to default.
[10:52:20.483] INFO: enter test to run
[10:52:32.287] INFO: test: exit no parameter change
[10:52:32.625] QUIET: Connection to board 33 closed.
[10:52:32.627] INFO: pXar: this is the end, my friend