[14:27:59.524] INFO: *** Welcome to pxar ***
[14:27:59.524] INFO: *** Today: 2016/04/01
[14:27:59.544] INFO: *** Version: v1.9.0-793-ge521-dirty
[14:27:59.544] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//dacParameters35_C15.dat
[14:27:59.579] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:27:59.579] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//defaultMaskFile.dat
[14:27:59.586] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C15.dat
[14:27:59.685] INFO: clk: 4
[14:27:59.685] INFO: ctr: 4
[14:27:59.685] INFO: sda: 19
[14:27:59.685] INFO: tin: 9
[14:27:59.685] INFO: level: 15
[14:27:59.685] INFO: triggerdelay: 0
[14:27:59.685] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[14:27:59.685] INFO: Log level: INFO
[14:27:59.702] QUIET: Connection to board DTB_WREKRL opened.
[14:27:59.706] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[14:27:59.709] INFO: RPC call hashes of host and DTB match: 398089610
[14:28:01.241] INFO: DUT info:
[14:28:01.241] INFO: The DUT currently contains the following objects:
[14:28:01.241] INFO: 2 TBM Cores tbm08c (2 ON)
[14:28:01.241] INFO: TBM Core alpha (0): 7 registers set
[14:28:01.241] INFO: TBM Core beta (1): 7 registers set
[14:28:01.241] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:28:01.241] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.242] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:01.646] INFO: enter 'restricted' command line mode
[14:28:01.646] INFO: enter test to run
[14:28:33.546] INFO: test: PixelAlive no parameter change
[14:28:33.546] INFO: running: pixelalive
[14:28:33.556] INFO: ----------------------------------------------------------------------
[14:28:33.556] 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:28:33.556] INFO: ----------------------------------------------------------------------
[14:28:33.874] INFO: Expecting 41600 events.
[14:28:38.226] INFO: 41600 events read in total (3634ms).
[14:28:38.392] INFO: Test took 4834ms.
[14:28:38.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:38.676] INFO: PixTestAlive::aliveTest() done with 782 decoding errors
[14:28:38.676] INFO: number of dead pixels (per ROC): 1 1 0 0 0 1 1 0 0 0 0 0 0 0 160 0
[14:28:38.703] INFO: enter test to run
[14:29:11.210] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:29:11.210] INFO: running: highrate
[14:29:11.210] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:29:11.474] INFO: ----------------------------------------------------------------------
[14:29:11.474] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:29:11.474] INFO: ----------------------------------------------------------------------
[14:29:11.474] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:29:11.474] INFO: edge/corner pixel THR is adjusted
[14:29:11.474] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:29:12.433] INFO: Collecting data for 5 seconds...
[14:29:17.450] INFO: Done with hot pixel readout
[14:29:29.048] INFO: PixTest:: pg_setup set to default.
[14:29:29.049] INFO: 14 hot pixels found in step 0
[14:29:30.064] INFO: Collecting data for 5 seconds...
[14:29:35.081] INFO: Done with hot pixel readout
[14:29:46.714] INFO: PixTest:: pg_setup set to default.
[14:29:46.715] INFO: 13 hot pixels found in step 1
[14:29:47.703] INFO: Collecting data for 5 seconds...
[14:29:52.721] INFO: Done with hot pixel readout
[14:30:04.263] INFO: PixTest:: pg_setup set to default.
[14:30:04.264] INFO: 8 hot pixels found in step 2
[14:30:05.251] INFO: Collecting data for 5 seconds...
[14:30:10.268] INFO: Done with hot pixel readout
[14:30:21.900] INFO: PixTest:: pg_setup set to default.
[14:30:21.900] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:30:21.900] INFO: 10 hot pixels found in step 3
[14:30:22.888] INFO: Collecting data for 5 seconds...
[14:30:27.904] INFO: Done with hot pixel readout
[14:30:37.032] INFO: PixTest:: pg_setup set to default.
[14:30:37.032] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:30:37.033] INFO: 5 hot pixels found in step 4
[14:30:38.020] INFO: Collecting data for 5 seconds...
[14:30:43.036] INFO: Done with hot pixel readout
[14:30:54.613] INFO: PixTest:: pg_setup set to default.
[14:30:54.613] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:30:54.614] INFO: 15 hot pixels found in step 5
[14:30:55.601] INFO: Collecting data for 5 seconds...
[14:31:00.611] INFO: Done with hot pixel readout
[14:31:12.198] INFO: PixTest:: pg_setup set to default.
[14:31:12.199] INFO: 4 hot pixels found in step 6
[14:31:13.187] INFO: Collecting data for 5 seconds...
[14:31:18.204] INFO: Done with hot pixel readout
[14:31:29.678] INFO: PixTest:: pg_setup set to default.
[14:31:29.678] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:31:29.678] INFO: 3 hot pixels found in step 7
[14:31:30.665] INFO: Collecting data for 5 seconds...
[14:31:35.683] INFO: Done with hot pixel readout
[14:31:47.273] INFO: PixTest:: pg_setup set to default.
[14:31:47.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:31:47.274] INFO: 12 hot pixels found in step 8
[14:31:48.263] INFO: Collecting data for 5 seconds...
[14:31:53.280] INFO: Done with hot pixel readout
[14:32:04.906] INFO: PixTest:: pg_setup set to default.
[14:32:04.907] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:04.907] INFO: 3 hot pixels found in step 9
[14:32:05.895] INFO: Collecting data for 5 seconds...
[14:32:10.912] INFO: Done with hot pixel readout
[14:32:22.478] INFO: PixTest:: pg_setup set to default.
[14:32:22.478] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:22.479] INFO: 8 hot pixels found in step 10
[14:32:23.466] INFO: Collecting data for 5 seconds...
[14:32:28.483] INFO: Done with hot pixel readout
[14:32:40.064] INFO: PixTest:: pg_setup set to default.
[14:32:40.064] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:40.065] INFO: 9 hot pixels found in step 11
[14:32:41.053] INFO: Collecting data for 5 seconds...
[14:32:46.070] INFO: Done with hot pixel readout
[14:32:57.687] INFO: PixTest:: pg_setup set to default.
[14:32:57.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:57.688] INFO: 7 hot pixels found in step 12
[14:32:58.675] INFO: Collecting data for 5 seconds...
[14:33:03.692] INFO: Done with hot pixel readout
[14:33:15.146] INFO: PixTest:: pg_setup set to default.
[14:33:15.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:33:15.147] INFO: 6 hot pixels found in step 13
[14:33:16.134] INFO: Collecting data for 5 seconds...
[14:33:21.151] INFO: Done with hot pixel readout
[14:33:32.713] INFO: PixTest:: pg_setup set to default.
[14:33:32.713] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:33:32.714] INFO: 7 hot pixels found in step 14
[14:33:32.745] INFO: 7 hot pixels could not be trimmed and have been masked.
[14:33:32.749] INFO: PixTest::trimHotPixels() done
[14:33:32.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C0.dat
[14:33:32.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C1.dat
[14:33:32.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C2.dat
[14:33:32.786] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C3.dat
[14:33:32.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C4.dat
[14:33:32.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C5.dat
[14:33:32.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C6.dat
[14:33:32.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C7.dat
[14:33:32.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C8.dat
[14:33:32.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C9.dat
[14:33:32.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C10.dat
[14:33:32.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C11.dat
[14:33:32.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C12.dat
[14:33:32.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C13.dat
[14:33:32.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C14.dat
[14:33:32.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C15.dat
[14:33:32.854] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//defaultMaskFile.dat
[14:33:32.869] INFO: enter test to run
[14:34:17.016] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:34:17.016] INFO: running: highrate
[14:34:17.020] INFO: ----------------------------------------------------------------------
[14:34:17.020] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:34:17.020] INFO: ----------------------------------------------------------------------
[14:34:17.020] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:34:17.020] INFO: edge/corner pixel THR is adjusted
[14:34:17.020] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:34:17.983] INFO: Collecting data for 1 seconds...
[14:34:18.987] INFO: Done with hot pixel readout
[14:34:23.035] INFO: PixTest:: pg_setup set to default.
[14:34:23.036] INFO: 0 hot pixels found in step 0
[14:34:23.041] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:34:23.130] INFO: PixTest::trimHotPixels() done
[14:34:23.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C0.dat
[14:34:23.137] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C1.dat
[14:34:23.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C2.dat
[14:34:23.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C3.dat
[14:34:23.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C4.dat
[14:34:23.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C5.dat
[14:34:23.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C6.dat
[14:34:23.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C7.dat
[14:34:23.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C8.dat
[14:34:23.182] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C9.dat
[14:34:23.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C10.dat
[14:34:23.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C11.dat
[14:34:23.198] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C12.dat
[14:34:23.203] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C13.dat
[14:34:23.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C14.dat
[14:34:23.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:23.219] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-H-1-02_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:23.229] INFO: enter test to run
[14:34:53.183] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:34:53.184] INFO: running: xray
[14:34:53.185] INFO: ----------------------------------------------------------------------
[14:34:53.185] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:34:53.185] INFO: ----------------------------------------------------------------------
[14:34:54.150] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:35:05.431] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:35:34.960] INFO: Resuming triggers.
[14:35:46.246] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:36:15.592] INFO: Resuming triggers.
[14:36:26.876] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:36:56.379] INFO: Resuming triggers.
[14:37:07.662] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:37:37.152] INFO: Resuming triggers.
[14:37:48.437] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:38:17.790] INFO: Resuming triggers.
[14:38:29.075] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:38:58.504] INFO: Resuming triggers.
[14:39:09.787] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:39:39.233] INFO: Resuming triggers.
[14:39:50.516] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:40:19.907] INFO: Resuming triggers.
[14:40:29.971] INFO: data taking finished, elapsed time: 100 seconds.
[14:40:53.021] INFO: PixTest:: pg_setup set to default.
[14:40:53.025] INFO: PixTestXray::doPhRun() done
[14:40:53.201] INFO: enter test to run
[14:41:29.836] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:41:29.836] INFO: running: xray
[14:41:29.838] INFO: ----------------------------------------------------------------------
[14:41:29.838] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:41:29.838] INFO: ----------------------------------------------------------------------
[14:41:30.801] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:41:37.370] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:42:07.462] INFO: Resuming triggers.
[14:42:14.031] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:42:43.757] INFO: Resuming triggers.
[14:42:50.328] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:43:20.300] INFO: Resuming triggers.
[14:43:26.873] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:43:56.856] INFO: Resuming triggers.
[14:44:03.426] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:44:33.466] INFO: Resuming triggers.
[14:44:40.040] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:45:10.033] INFO: Resuming triggers.
[14:45:16.609] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:45:46.589] INFO: Resuming triggers.
[14:45:53.162] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:46:23.231] INFO: Resuming triggers.
[14:46:29.801] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:46:59.825] INFO: Resuming triggers.
[14:47:06.398] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:47:36.441] INFO: Resuming triggers.
[14:47:43.011] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:48:12.913] INFO: Resuming triggers.
[14:48:19.484] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:48:49.401] INFO: Resuming triggers.
[14:48:55.969] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:49:25.955] INFO: Resuming triggers.
[14:49:32.526] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:50:02.534] INFO: Resuming triggers.
[14:50:09.101] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:50:39.046] INFO: Resuming triggers.
[14:50:40.815] INFO: data taking finished, elapsed time: 100 seconds.
[14:50:47.770] INFO: PixTest:: pg_setup set to default.
[14:50:47.773] INFO: PixTestXray::doPhRun() done
[14:50:47.922] INFO: enter test to run
[14:52:13.104] INFO: test: HighRate no parameter change
[14:52:13.104] INFO: running: highrate
[14:52:13.105] INFO: ----------------------------------------------------------------------
[14:52:13.105] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:52:13.105] INFO: ----------------------------------------------------------------------
[14:52:13.246] INFO: Expecting 768 events.
[14:52:14.380] INFO: 768 events read in total (419ms).
[14:52:14.380] INFO: Test took 1269ms.
[14:52:15.183] INFO: Expecting 41600 events.
[14:52:18.236] INFO: 41600 events read in total (2526ms).
[14:52:18.237] INFO: Test took 3848ms.
[14:52:18.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:18.997] INFO: Expecting 41600 events.
[14:52:22.166] INFO: 41600 events read in total (2642ms).
[14:52:22.167] INFO: Test took 3882ms.
[14:52:22.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:22.926] INFO: Expecting 41600 events.
[14:52:26.173] INFO: 41600 events read in total (2720ms).
[14:52:26.174] INFO: Test took 3958ms.
[14:52:26.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:26.931] INFO: Expecting 41600 events.
[14:52:30.168] INFO: 41600 events read in total (2710ms).
[14:52:30.169] INFO: Test took 3944ms.
[14:52:30.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:30.925] INFO: Expecting 41600 events.
[14:52:34.165] INFO: 41600 events read in total (2714ms).
[14:52:34.166] INFO: Test took 3946ms.
[14:52:34.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:34.922] INFO: Expecting 41600 events.
[14:52:38.162] INFO: 41600 events read in total (2713ms).
[14:52:38.163] INFO: Test took 3948ms.
[14:52:38.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:38.921] INFO: Expecting 41600 events.
[14:52:42.146] INFO: 41600 events read in total (2698ms).
[14:52:42.147] INFO: Test took 3933ms.
[14:52:42.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:42.904] INFO: Expecting 41600 events.
[14:52:46.152] INFO: 41600 events read in total (2721ms).
[14:52:46.153] INFO: Test took 3956ms.
[14:52:46.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:46.909] INFO: Expecting 41600 events.
[14:52:50.151] INFO: 41600 events read in total (2715ms).
[14:52:50.152] INFO: Test took 3949ms.
[14:52:50.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:50.910] INFO: Expecting 41600 events.
[14:52:54.161] INFO: 41600 events read in total (2725ms).
[14:52:54.162] INFO: Test took 3960ms.
[14:52:54.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:54.924] INFO: Expecting 41600 events.
[14:52:58.188] INFO: 41600 events read in total (2737ms).
[14:52:58.189] INFO: Test took 3977ms.
[14:52:58.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:58.946] INFO: Expecting 41600 events.
[14:53:02.176] INFO: 41600 events read in total (2703ms).
[14:53:02.177] INFO: Test took 3936ms.
[14:53:02.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:02.938] INFO: Expecting 41600 events.
[14:53:06.184] INFO: 41600 events read in total (2720ms).
[14:53:06.185] INFO: Test took 3956ms.
[14:53:06.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:06.944] INFO: Expecting 41600 events.
[14:53:10.200] INFO: 41600 events read in total (2729ms).
[14:53:10.201] INFO: Test took 3966ms.
[14:53:10.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:10.957] INFO: Expecting 41600 events.
[14:53:14.200] INFO: 41600 events read in total (2716ms).
[14:53:14.201] INFO: Test took 3949ms.
[14:53:14.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:14.961] INFO: Expecting 41600 events.
[14:53:18.217] INFO: 41600 events read in total (2729ms).
[14:53:18.218] INFO: Test took 3965ms.
[14:53:18.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:18.975] INFO: Expecting 41600 events.
[14:53:22.214] INFO: 41600 events read in total (2712ms).
[14:53:22.215] INFO: Test took 3946ms.
[14:53:22.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:22.973] INFO: Expecting 41600 events.
[14:53:26.201] INFO: 41600 events read in total (2701ms).
[14:53:26.202] INFO: Test took 3934ms.
[14:53:26.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:26.963] INFO: Expecting 41600 events.
[14:53:30.196] INFO: 41600 events read in total (2706ms).
[14:53:30.197] INFO: Test took 3943ms.
[14:53:30.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:30.957] INFO: Expecting 41600 events.
[14:53:34.068] INFO: 41600 events read in total (2585ms).
[14:53:34.069] INFO: Test took 3822ms.
[14:53:34.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:34.468] INFO: enter test to run
[14:53:49.183] INFO: test: HighRate no parameter change
[14:53:49.183] INFO: running: highrate
[14:53:49.185] INFO: ----------------------------------------------------------------------
[14:53:49.185] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:53:49.185] INFO: ----------------------------------------------------------------------
[14:53:49.799] INFO: Expecting 208000 events.
[14:53:53.336] WARNING: Channel 1 ROC 7: Readback start marker after 11 readouts!
[14:53:53.336] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fd 80c0 40c8 5 248e 40c8 5 24a5 40c8 5 248f 40c8 5 248d 40c8 5 2485 69b 2a48 40c8 5 248b 40c8 5 24a1 40c8 5 2489 e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f7 8040 40c8 5 288f 40c8 5 28a7 40c9 5 288b d4 264f 40c9 5 2888 40c8 5 2885 44a 2866 742 2248 40c8 5 2882 40c8 5 28a3 40 2046 40c8 5 288f e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f8 80b1 40c9 5 28a0 40c9 5 288b 40c9 5 2883 40c9 5 2889 74a 2045 40c9 5 2883 48c 2849 40c9 5 288a 321 2466 40c9 5 28a0 40c9 5 288b e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f9 80c0 40c9 5 28a4 40c9 5 288f 40c8 5 288c 40c8 5 2882 40c9 5 2885 40c9 5 2888 40c9 5 288f 40c9 5 288e e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fa 8000 40c8 5 248e 40c8 5 24a6 40c8 5 2483 40c8 5 2481 40c8 5 248d 40c8 5 24a2 41d 268a 40c8 5 248f 40ca 248f 553 2666 40c8 5 2487 e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fb 8040 40c8 5 2489 40c8 5 24a5 dc 284f 40c9 5 248b 40c9 5 248b 40c8 5 2489 40c8 5 248f 40c8 5 24a4 40c8 5 2486 e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fc 80b1 40c9 5 248f 40c9 12 246a 5 248f 40c8 5 248b 40c8 5 248f 40c9 5 2482 40c9 5 2489 40c9 5 24a2 40c9 5 248a e002 c000
[14:53:53.336] WARNING: Channel 1 ROC 7: Readback start marker after 5 readouts!
[14:53:53.336] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a102 8000 40c8 5 248f 40c8 5 248f 44a 2a69 40c8 5 2485 40c9 5 2485 549 2646 40c8 5 2486 40c8 5 248a 40c9 5 24a3 40c9 5 2488 250 2a4d e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fc 80b1 40c9 5 248f 40c9 12 246a 5 248f 40c8 5 248b 40c8 5 248f 40c9 5 2482 40c9 5 2489 40c9 5 24a2 40c9 5 248a e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fd 80c0 40c8 5 248e 40c8 5 24a5 40c8 5 248f 40c8 5 248d 40c8 5 2485 69b 2a48 40c8 5 248b 40c8 5 24a1 40c8 5 2489 e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1fe 8000 40c8 5 248d 40c8 5 24a6 683 2048 6dd 2a4a 40ca 5 248c 40ca 5 2485 54c 2442 40c8 5 2483 449 284f 40c8 5 248a 40c8 5 24a2 40c8 5 248d e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ff 8040 40ca 5 248c 40ca 5 24a2 40a 204a 40c9 5 248a 24c 284f 411 2a49 40c9 5 2489 40ca 5 2483 40ca 5 248b 40ca 5 24a3 40ca 5 2485 e002 c000
[14:53:53.336] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a100 80b1 40c9 5 248f 40c9 5 248f 342 204f 40c8 5 2485 40c8 5 2485 315 28a2 40c9 5 246f 40c9 5 248f 40c9 5 24a5 40c9 5 2485 e002 c000
[14:53:53.337] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a101 80c0 40c8 5 248c 40c8 5 248f 40c9 5 248f 40c9 5 2489 505 2249 40c9 5 2488 40c9 5 248b 40c9 5 24a2 40c9 5 248c e002 c000
[14:54:01.689] INFO: 208000 events read in total (11363ms).
[14:54:01.692] INFO: Test took 12499ms.
[14:54:01.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:02.080] INFO: number of dead pixels (per ROC): 1 1 0 0 0 1 1 0 0 0 0 0 0 0 160 0
[14:54:02.080] INFO: number of red-efficiency pixels: 96 53 123 110 142 134 141 110 88 134 118 102 88 68 199 23
[14:54:02.080] INFO: number of X-ray hits detected: 67588 45265 69276 101963 108565 113233 109172 81167 74512 91504 91347 77660 81491 49169 21522 23002
[14:54:02.080] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:54:02.080] INFO: number of Vcal hits detected: 207854 207887 207871 207884 207854 207816 207806 207888 207911 207862 207881 207894 207912 207932 199961 207976
[14:54:02.080] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 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
[14:54:02.080] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 96.1 100.0
[14:54:02.080] INFO: X-ray hit rate [MHz/cm2]: 19.8 13.3 20.3 29.9 31.8 33.2 32.0 23.8 21.8 26.8 26.8 22.8 23.9 14.4 6.3 6.7
[14:54:02.080] INFO: PixTestHighRate::doXPixelAlive() done
[14:54:02.134] INFO: PixTest:: pg_setup set to default.
[14:54:02.146] INFO: enter test to run
[14:54:28.255] INFO: test: HighRate no parameter change
[14:54:28.255] INFO: running: highrate
[14:54:28.256] INFO: ----------------------------------------------------------------------
[14:54:28.256] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:54:28.256] INFO: ----------------------------------------------------------------------
[14:54:28.872] INFO: Expecting 208000 events.
[14:54:42.515] INFO: 208000 events read in total (13116ms).
[14:54:42.521] INFO: Test took 14254ms.
[14:54:42.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:43.109] INFO: number of dead pixels (per ROC): 1 1 0 0 0 1 1 0 0 0 0 0 0 0 160 0
[14:54:43.110] INFO: number of red-efficiency pixels: 267 148 358 395 549 428 534 347 247 333 342 325 252 219 217 74
[14:54:43.110] INFO: number of X-ray hits detected: 146079 98904 148066 219410 233782 241236 234313 175144 160429 197080 195848 166785 176219 106004 46480 49232
[14:54:43.110] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:54:43.110] INFO: number of Vcal hits detected: 207674 207783 207601 207584 207384 207496 207359 207635 207738 207643 207633 207659 207729 207768 199941 207924
[14:54:43.110] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:54:43.110] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 96.1 100.0
[14:54:43.110] INFO: X-ray hit rate [MHz/cm2]: 42.8 29.0 43.4 64.3 68.5 70.7 68.7 51.3 47.0 57.8 57.4 48.9 51.7 31.1 13.6 14.4
[14:54:43.110] INFO: PixTestHighRate::doXPixelAlive() done
[14:54:43.160] INFO: PixTest:: pg_setup set to default.
[14:54:43.174] INFO: enter test to run
[14:54:59.614] INFO: test: HighRate no parameter change
[14:54:59.615] INFO: running: highrate
[14:54:59.616] INFO: ----------------------------------------------------------------------
[14:54:59.616] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:54:59.616] INFO: ----------------------------------------------------------------------
[14:55:00.231] INFO: Expecting 208000 events.
[14:55:15.992] INFO: 208000 events read in total (15234ms).
[14:55:15.000] INFO: Test took 16374ms.
[14:55:16.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:16.800] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 1 0 0 0 0 0 0 0 160 0
[14:55:16.800] INFO: number of red-efficiency pixels: 633 282 850 890 1333 1102 1357 853 486 755 741 756 572 463 294 100
[14:55:16.800] INFO: number of X-ray hits detected: 227981 154514 232002 341584 363990 375973 365382 272085 249662 307923 305300 260863 275132 165307 72736 77555
[14:55:16.800] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:55:16.800] INFO: number of Vcal hits detected: 207209 207607 206845 206956 206254 206583 206110 206856 207462 207138 207120 207112 207365 207442 199861 207898
[14:55:16.800] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.5 99.2 99.4 99.2 99.5 99.8 99.6 99.6 99.6 99.7 99.8 99.9 100.0
[14:55:16.800] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.4 99.5 99.2 99.3 99.1 99.5 99.7 99.6 99.6 99.6 99.7 99.7 96.1 100.0
[14:55:16.800] INFO: X-ray hit rate [MHz/cm2]: 66.8 45.3 68.0 100.1 106.7 110.2 107.1 79.8 73.2 90.3 89.5 76.5 80.6 48.5 21.3 22.7
[14:55:16.800] INFO: PixTestHighRate::doXPixelAlive() done
[14:55:16.846] INFO: PixTest:: pg_setup set to default.
[14:55:16.860] INFO: enter test to run
[14:55:22.694] INFO: test: exit no parameter change
[14:55:23.006] QUIET: Connection to board 33 closed.
[14:55:23.007] INFO: pXar: this is the end, my friend