[13:44:58.433] INFO: *** Welcome to pxar ***
[13:44:58.433] INFO: *** Today: 2016/06/28
[13:44:58.845] INFO: *** Version: v1.9.0-814-g7497
[13:44:58.845] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C15.dat
[13:44:58.846] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:44:58.847] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[13:44:58.847] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[13:44:58.915] INFO: clk: 4
[13:44:58.915] INFO: ctr: 4
[13:44:58.915] INFO: sda: 19
[13:44:58.915] INFO: tin: 9
[13:44:58.915] INFO: level: 15
[13:44:58.915] INFO: triggerdelay: 0
[13:44:58.915] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:44:58.915] INFO: Log level: INFO
[13:44:58.932] QUIET: Connection to board DTB_WREK4U opened.
[13:44:58.936] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[13:44:58.938] INFO: RPC call hashes of host and DTB match: 398089610
[13:45:00.468] INFO: DUT info:
[13:45:00.468] INFO: The DUT currently contains the following objects:
[13:45:00.468] INFO: 2 TBM Cores tbm08c (2 ON)
[13:45:00.468] INFO: TBM Core alpha (0): 7 registers set
[13:45:00.468] INFO: TBM Core beta (1): 7 registers set
[13:45:00.468] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:45:00.468] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.468] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.468] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.468] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.469] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:45:00.873] INFO: enter 'restricted' command line mode
[13:45:00.873] INFO: enter test to run
[13:45:10.725] INFO: test: PixelAlive no parameter change
[13:45:10.725] INFO: running: pixelalive
[13:45:10.734] INFO: ----------------------------------------------------------------------
[13:45:10.734] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:45:10.734] INFO: ----------------------------------------------------------------------
[13:45:11.050] INFO: Expecting 41600 events.
[13:45:15.398] INFO: 41600 events read in total (3629ms).
[13:45:15.564] INFO: Test took 4826ms.
[13:45:15.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:15.840] INFO: PixTestAlive::aliveTest() done
[13:45:15.840] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 2 0 1 0 0 0 0 0 0
[13:45:15.872] INFO: enter test to run
[13:45:32.701] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:45:32.701] INFO: running: highrate
[13:45:32.702] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:45:32.856] INFO: ----------------------------------------------------------------------
[13:45:32.856] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:45:32.856] INFO: ----------------------------------------------------------------------
[13:45:32.856] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:45:32.856] INFO: edge/corner pixel THR is adjusted
[13:45:32.857] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:45:33.815] INFO: Collecting data for 5 seconds...
[13:45:38.833] INFO: Done with hot pixel readout
[13:45:51.105] INFO: PixTest:: pg_setup set to default.
[13:45:51.106] INFO: 3 hot pixels found in step 0
[13:45:52.124] INFO: Collecting data for 5 seconds...
[13:45:57.140] INFO: Done with hot pixel readout
[13:46:09.354] INFO: PixTest:: pg_setup set to default.
[13:46:09.355] INFO: 2 hot pixels found in step 1
[13:46:10.347] INFO: Collecting data for 5 seconds...
[13:46:15.364] INFO: Done with hot pixel readout
[13:46:27.586] INFO: PixTest:: pg_setup set to default.
[13:46:27.587] INFO: 6 hot pixels found in step 2
[13:46:28.580] INFO: Collecting data for 5 seconds...
[13:46:33.597] INFO: Done with hot pixel readout
[13:46:45.820] INFO: PixTest:: pg_setup set to default.
[13:46:45.821] INFO: 9 hot pixels found in step 3
[13:46:46.812] INFO: Collecting data for 5 seconds...
[13:46:51.829] INFO: Done with hot pixel readout
[13:47:04.070] INFO: PixTest:: pg_setup set to default.
[13:47:04.070] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:47:04.070] INFO: 8 hot pixels found in step 4
[13:47:05.063] INFO: Collecting data for 5 seconds...
[13:47:10.080] INFO: Done with hot pixel readout
[13:47:22.332] INFO: PixTest:: pg_setup set to default.
[13:47:22.333] INFO: 0 hot pixels found in step 5
[13:47:22.368] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:47:22.372] INFO: PixTest::trimHotPixels() done
[13:47:22.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[13:47:22.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[13:47:22.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[13:47:22.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[13:47:22.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[13:47:22.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[13:47:22.405] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[13:47:22.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[13:47:22.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[13:47:22.421] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[13:47:22.426] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[13:47:22.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[13:47:22.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[13:47:22.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[13:47:22.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[13:47:22.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[13:47:22.457] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[13:47:22.467] INFO: enter test to run
[13:47:52.068] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:47:52.068] INFO: running: highrate
[13:47:52.073] INFO: ----------------------------------------------------------------------
[13:47:52.073] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:47:52.073] INFO: ----------------------------------------------------------------------
[13:47:52.073] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:47:52.073] INFO: edge/corner pixel THR is adjusted
[13:47:52.073] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:47:53.031] INFO: Collecting data for 1 seconds...
[13:47:54.035] INFO: Done with hot pixel readout
[13:47:58.307] INFO: PixTest:: pg_setup set to default.
[13:47:58.308] INFO: 0 hot pixels found in step 0
[13:47:58.313] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:47:58.398] INFO: PixTest::trimHotPixels() done
[13:47:58.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[13:47:58.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[13:47:58.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[13:47:58.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[13:47:58.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[13:47:58.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[13:47:58.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[13:47:58.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[13:47:58.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[13:47:58.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[13:47:58.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[13:47:58.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[13:47:58.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[13:47:58.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[13:47:58.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[13:47:58.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[13:47:58.486] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-16_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[13:47:58.496] INFO: enter test to run
[13:48:23.916] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:48:23.916] INFO: running: xray
[13:48:23.917] INFO: ----------------------------------------------------------------------
[13:48:23.917] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:48:23.917] INFO: ----------------------------------------------------------------------
[13:48:24.881] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:48:35.764] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:49:06.118] INFO: Resuming triggers.
[13:49:17.003] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:49:46.667] INFO: Resuming triggers.
[13:49:57.557] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:50:27.091] INFO: Resuming triggers.
[13:50:37.976] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:51:07.277] INFO: Resuming triggers.
[13:51:18.166] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:51:47.726] INFO: Resuming triggers.
[13:51:58.614] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[13:52:28.133] INFO: Resuming triggers.
[13:52:39.020] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:53:08.577] INFO: Resuming triggers.
[13:53:19.468] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:53:48.954] INFO: Resuming triggers.
[13:53:59.847] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[13:54:29.902] INFO: Resuming triggers.
[13:54:32.260] INFO: data taking finished, elapsed time: 100 seconds.
[13:54:39.020] INFO: PixTest:: pg_setup set to default.
[13:54:39.024] INFO: PixTestXray::doPhRun() done
[13:54:39.164] INFO: enter test to run
[13:55:09.585] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:55:09.585] INFO: running: xray
[13:55:09.586] INFO: ----------------------------------------------------------------------
[13:55:09.587] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:55:09.587] INFO: ----------------------------------------------------------------------
[13:55:10.565] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:55:16.717] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:55:47.230] INFO: Resuming triggers.
[13:55:53.381] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:56:25.105] INFO: Resuming triggers.
[13:56:31.256] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[13:57:01.244] INFO: Resuming triggers.
[13:57:07.393] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[13:57:37.448] INFO: Resuming triggers.
[13:57:43.599] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:58:13.677] INFO: Resuming triggers.
[13:58:19.827] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[13:58:50.068] INFO: Resuming triggers.
[13:58:56.218] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:59:27.074] INFO: Resuming triggers.
[13:59:33.226] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:00:05.111] INFO: Resuming triggers.
[14:00:11.262] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:00:41.304] INFO: Resuming triggers.
[14:00:47.455] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:01:17.529] INFO: Resuming triggers.
[14:01:23.682] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:01:53.739] INFO: Resuming triggers.
[14:01:59.890] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:02:29.995] INFO: Resuming triggers.
[14:02:36.148] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:03:06.229] INFO: Resuming triggers.
[14:03:12.383] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:03:42.363] INFO: Resuming triggers.
[14:03:48.515] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:04:18.579] INFO: Resuming triggers.
[14:04:24.732] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:04:55.041] INFO: Resuming triggers.
[14:04:56.967] INFO: data taking finished, elapsed time: 100 seconds.
[14:05:06.669] INFO: PixTest:: pg_setup set to default.
[14:05:06.673] INFO: PixTestXray::doPhRun() done
[14:05:06.822] INFO: enter test to run
[14:05:40.093] INFO: test: HighRate no parameter change
[14:05:40.093] INFO: running: highrate
[14:05:40.107] INFO: ----------------------------------------------------------------------
[14:05:40.107] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:05:40.107] INFO: ----------------------------------------------------------------------
[14:05:40.266] INFO: Expecting 768 events.
[14:05:41.407] INFO: 768 events read in total (418ms).
[14:05:41.407] INFO: Test took 1294ms.
[14:05:42.210] INFO: Expecting 41600 events.
[14:05:45.351] INFO: 41600 events read in total (2614ms).
[14:05:45.352] INFO: Test took 3938ms.
[14:05:45.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:46.111] INFO: Expecting 41600 events.
[14:05:49.429] INFO: 41600 events read in total (2791ms).
[14:05:49.430] INFO: Test took 4020ms.
[14:05:49.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:50.180] INFO: Expecting 41600 events.
[14:05:53.491] INFO: 41600 events read in total (2784ms).
[14:05:53.492] INFO: Test took 4002ms.
[14:05:53.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:54.225] INFO: Expecting 41600 events.
[14:05:57.515] INFO: 41600 events read in total (2763ms).
[14:05:57.516] INFO: Test took 3966ms.
[14:05:57.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:58.260] INFO: Expecting 41600 events.
[14:06:01.614] INFO: 41600 events read in total (2827ms).
[14:06:01.615] INFO: Test took 4041ms.
[14:06:01.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:02.369] INFO: Expecting 41600 events.
[14:06:05.687] INFO: 41600 events read in total (2791ms).
[14:06:05.688] INFO: Test took 4015ms.
[14:06:05.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:06.435] INFO: Expecting 41600 events.
[14:06:09.758] INFO: 41600 events read in total (2796ms).
[14:06:09.759] INFO: Test took 4012ms.
[14:06:09.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:10.508] INFO: Expecting 41600 events.
[14:06:13.839] INFO: 41600 events read in total (2804ms).
[14:06:13.840] INFO: Test took 4020ms.
[14:06:13.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:14.591] INFO: Expecting 41600 events.
[14:06:17.863] INFO: 41600 events read in total (2745ms).
[14:06:17.864] INFO: Test took 3964ms.
[14:06:17.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:18.619] INFO: Expecting 41600 events.
[14:06:21.929] INFO: 41600 events read in total (2783ms).
[14:06:21.930] INFO: Test took 4006ms.
[14:06:21.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:22.683] INFO: Expecting 41600 events.
[14:06:25.985] INFO: 41600 events read in total (2776ms).
[14:06:25.986] INFO: Test took 3998ms.
[14:06:26.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:26.740] INFO: Expecting 41600 events.
[14:06:30.019] INFO: 41600 events read in total (2752ms).
[14:06:30.020] INFO: Test took 3976ms.
[14:06:30.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:30.769] INFO: Expecting 41600 events.
[14:06:34.051] INFO: 41600 events read in total (2756ms).
[14:06:34.052] INFO: Test took 3973ms.
[14:06:34.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:34.805] INFO: Expecting 41600 events.
[14:06:38.146] INFO: 41600 events read in total (2814ms).
[14:06:38.147] INFO: Test took 4037ms.
[14:06:38.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:38.891] INFO: Expecting 41600 events.
[14:06:42.208] INFO: 41600 events read in total (2790ms).
[14:06:42.209] INFO: Test took 4002ms.
[14:06:42.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:42.962] INFO: Expecting 41600 events.
[14:06:46.231] INFO: 41600 events read in total (2742ms).
[14:06:46.232] INFO: Test took 3964ms.
[14:06:46.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:46.987] INFO: Expecting 41600 events.
[14:06:50.321] INFO: 41600 events read in total (2807ms).
[14:06:50.322] INFO: Test took 4031ms.
[14:06:50.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:51.066] INFO: Expecting 41600 events.
[14:06:54.338] INFO: 41600 events read in total (2745ms).
[14:06:54.339] INFO: Test took 3957ms.
[14:06:54.377] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:55.089] INFO: Expecting 41600 events.
[14:06:58.290] INFO: 41600 events read in total (2675ms).
[14:06:58.291] INFO: Test took 3893ms.
[14:06:58.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:59.039] INFO: Expecting 41600 events.
[14:07:02.229] INFO: 41600 events read in total (2663ms).
[14:07:02.230] INFO: Test took 3880ms.
[14:07:02.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:02.625] INFO: enter test to run
[14:09:35.411] INFO: test: HighRate no parameter change
[14:09:35.411] INFO: running: highrate
[14:09:35.413] INFO: ----------------------------------------------------------------------
[14:09:35.413] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:09:35.413] INFO: ----------------------------------------------------------------------
[14:09:36.029] INFO: Expecting 208000 events.
[14:09:48.163] INFO: 208000 events read in total (11607ms).
[14:09:48.167] INFO: Test took 12746ms.
[14:09:48.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:48.592] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 2 0 1 0 0 0 0 0 0
[14:09:48.592] INFO: number of red-efficiency pixels: 73 56 95 162 148 181 199 184 122 140 172 116 154 79 24 31
[14:09:48.592] INFO: number of X-ray hits detected: 71622 47228 73866 120930 127055 135135 131368 92366 92928 120304 117367 99415 105548 64298 24209 27318
[14:09:48.592] 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:09:48.592] INFO: number of Vcal hits detected: 207923 207894 207903 207836 207845 207812 207797 207678 207877 207806 207823 207880 207844 207918 207975 207968
[14:09:48.592] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:09:48.592] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:09:48.592] INFO: X-ray hit rate [MHz/cm2]: 21.0 13.8 21.7 35.4 37.2 39.6 38.5 27.1 27.2 35.3 34.4 29.1 30.9 18.8 7.1 8.0
[14:09:48.592] INFO: PixTestHighRate::doXPixelAlive() done
[14:09:48.640] INFO: PixTest:: pg_setup set to default.
[14:09:48.653] INFO: enter test to run
[14:10:09.787] INFO: test: HighRate no parameter change
[14:10:09.787] INFO: running: highrate
[14:10:09.789] INFO: ----------------------------------------------------------------------
[14:10:09.789] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:10:09.789] INFO: ----------------------------------------------------------------------
[14:10:10.421] INFO: Expecting 208000 events.
[14:10:24.991] INFO: 208000 events read in total (14043ms).
[14:10:24.996] INFO: Test took 15196ms.
[14:10:25.353] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:25.674] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 2 0 1 0 0 0 0 0 0
[14:10:25.674] INFO: number of red-efficiency pixels: 251 125 350 584 468 743 704 523 353 465 608 322 493 225 69 59
[14:10:25.674] INFO: number of X-ray hits detected: 146575 96038 151579 245570 256052 272958 266353 188177 188588 245132 239293 201741 214920 130385 49327 54866
[14:10:25.674] 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:10:25.674] INFO: number of Vcal hits detected: 207729 207822 207606 207339 207484 207161 207210 207270 207616 207461 207317 207660 207451 207759 207929 207941
[14:10:25.674] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.6 99.7 99.7 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[14:10:25.674] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.6 99.6 99.6 99.8 99.7 99.7 99.8 99.7 99.9 100.0 100.0
[14:10:25.674] INFO: X-ray hit rate [MHz/cm2]: 43.0 28.1 44.4 72.0 75.1 80.0 78.1 55.2 55.3 71.8 70.1 59.1 63.0 38.2 14.5 16.1
[14:10:25.674] INFO: PixTestHighRate::doXPixelAlive() done
[14:10:25.719] INFO: PixTest:: pg_setup set to default.
[14:10:25.734] INFO: enter test to run
[14:10:45.203] INFO: test: HighRate no parameter change
[14:10:45.203] INFO: running: highrate
[14:10:45.204] INFO: ----------------------------------------------------------------------
[14:10:45.204] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:10:45.204] INFO: ----------------------------------------------------------------------
[14:10:45.825] INFO: Expecting 208000 events.
[14:11:03.026] INFO: 208000 events read in total (16674ms).
[14:11:03.034] INFO: Test took 17821ms.
[14:11:03.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:03.948] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 2 0 1 0 0 0 0 0 0
[14:11:03.948] INFO: number of red-efficiency pixels: 524 202 754 1377 1157 1754 1602 1046 815 1062 1360 739 1045 474 95 77
[14:11:03.948] INFO: number of X-ray hits detected: 220456 145035 228276 370062 387339 411783 401116 283222 284380 368817 359701 303545 324827 197247 74838 83940
[14:11:03.948] 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:11:03.948] INFO: number of Vcal hits detected: 207359 207728 206945 206134 206547 205467 205695 206430 206994 206623 206197 207107 206657 207438 207901 207920
[14:11:03.948] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.2 99.4 98.9 99.0 99.4 99.6 99.4 99.2 99.6 99.4 99.8 100.0 100.0
[14:11:03.949] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.1 99.3 98.8 98.9 99.2 99.5 99.3 99.1 99.6 99.4 99.7 100.0 100.0
[14:11:03.949] INFO: X-ray hit rate [MHz/cm2]: 64.6 42.5 66.9 108.5 113.5 120.7 117.6 83.0 83.4 108.1 105.4 89.0 95.2 57.8 21.9 24.6
[14:11:03.949] INFO: PixTestHighRate::doXPixelAlive() done
[14:11:03.994] INFO: PixTest:: pg_setup set to default.
[14:11:04.013] INFO: enter test to run
[14:11:29.611] INFO: test: exit no parameter change
[14:11:29.934] QUIET: Connection to board 32 closed.
[14:11:29.935] INFO: pXar: this is the end, my friend