[12:19:30.468] INFO: *** Welcome to pxar ***
[12:19:30.468] INFO: *** Today: 2016/03/25
[12:19:30.483] INFO: *** Version: prod-12-dirty
[12:19:30.483] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//dacParameters35_C15.dat
[12:19:30.507] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:19:30.517] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//defaultMaskFile.dat
[12:19:30.528] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C15.dat
[12:19:30.619] INFO: clk: 4
[12:19:30.619] INFO: ctr: 4
[12:19:30.619] INFO: sda: 19
[12:19:30.619] INFO: tin: 9
[12:19:30.619] INFO: level: 15
[12:19:30.619] INFO: triggerdelay: 0
[12:19:30.619] QUIET: Instanciating API for pxar prod-12
[12:19:30.619] INFO: Log level: INFO
[12:19:30.636] QUIET: Connection to board DTB_WREKRL opened.
[12:19:30.640] 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:
------------------------------------------------------
[12:19:30.642] INFO: RPC call hashes of host and DTB match: 398089610
[12:19:32.173] INFO: DUT info:
[12:19:32.173] INFO: The DUT currently contains the following objects:
[12:19:32.173] INFO: 2 TBM Cores tbm08c (2 ON)
[12:19:32.173] INFO: TBM Core alpha (0): 7 registers set
[12:19:32.173] INFO: TBM Core beta (1): 7 registers set
[12:19:32.173] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:19:32.173] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.173] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.174] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:32.577] INFO: enter 'restricted' command line mode
[12:19:32.577] INFO: enter test to run
[12:19:40.642] INFO: test: PixelAlive no parameter change
[12:19:40.642] INFO: running: pixelalive
[12:19:40.651] INFO: ----------------------------------------------------------------------
[12:19:40.651] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:19:40.651] INFO: ----------------------------------------------------------------------
[12:19:40.974] INFO: Expecting 41600 events.
[12:19:45.313] INFO: 41600 events read in total (3621ms).
[12:19:45.478] INFO: Test took 4824ms.
[12:19:45.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:45.752] INFO: PixTestAlive::aliveTest() done
[12:19:45.752] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[12:19:45.779] INFO: enter test to run
[12:20:14.273] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=150;maskuntrimmable=0<-
[12:20:14.274] INFO: running: highrate
[12:20:14.274] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:20:14.500] INFO: ----------------------------------------------------------------------
[12:20:14.501] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:20:14.501] INFO: ----------------------------------------------------------------------
[12:20:14.501] INFO: THR = 150, corresponding to ~ 80 MHz/cm2
[12:20:14.501] INFO: edge/corner pixel THR is adjusted
[12:20:14.501] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:20:15.460] INFO: Collecting data for 5 seconds...
[12:20:20.478] INFO: Done with hot pixel readout
[12:20:30.773] INFO: PixTest:: pg_setup set to default.
[12:20:30.773] INFO: 0 hot pixels found in step 0
[12:20:30.831] INFO: PixTest::trimHotPixels() done
[12:20:30.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C0.dat
[12:20:30.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C1.dat
[12:20:30.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C2.dat
[12:20:30.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C3.dat
[12:20:30.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C4.dat
[12:20:30.913] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C5.dat
[12:20:30.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C6.dat
[12:20:30.929] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C7.dat
[12:20:30.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C8.dat
[12:20:30.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C9.dat
[12:20:30.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C10.dat
[12:20:30.959] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C11.dat
[12:20:30.966] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C12.dat
[12:20:30.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C13.dat
[12:20:30.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C14.dat
[12:20:30.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C15.dat
[12:20:31.007] INFO: enter test to run
[12:20:58.681] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=150;maskuntrimmable=0<-
[12:20:58.681] INFO: running: highrate
[12:20:58.686] INFO: ----------------------------------------------------------------------
[12:20:58.686] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:20:58.686] INFO: ----------------------------------------------------------------------
[12:20:58.686] INFO: THR = 150, corresponding to ~ 400 MHz/cm2
[12:20:58.686] INFO: edge/corner pixel THR is adjusted
[12:20:58.686] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:20:59.643] INFO: Collecting data for 1 seconds...
[12:21:00.647] INFO: Done with hot pixel readout
[12:21:03.708] INFO: PixTest:: pg_setup set to default.
[12:21:03.709] INFO: 0 hot pixels found in step 0
[12:21:03.842] INFO: PixTest::trimHotPixels() done
[12:21:03.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C0.dat
[12:21:03.854] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C1.dat
[12:21:03.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C2.dat
[12:21:03.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C3.dat
[12:21:03.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C4.dat
[12:21:03.884] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C5.dat
[12:21:03.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C6.dat
[12:21:03.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C7.dat
[12:21:03.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C8.dat
[12:21:03.913] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C9.dat
[12:21:03.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C10.dat
[12:21:03.928] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C11.dat
[12:21:03.935] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C12.dat
[12:21:03.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C13.dat
[12:21:03.950] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C14.dat
[12:21:03.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//trimParameters35_C15.dat
[12:21:03.974] INFO: enter test to run
[12:21:47.193] INFO: test: Xray setting parameters: ->savemaskfile=1<-
[12:21:47.193] INFO: running: xray
[12:21:47.198] INFO: ----------------------------------------------------------------------
[12:21:47.198] INFO: PixTest::maskHotPixels() running for 10 seconds with 100 kHz trigger rate
[12:21:47.198] INFO: ----------------------------------------------------------------------
[12:21:48.156] INFO: PixTestHighRate::maskHotPixels start TriggerLoop with period 404 and duration 10 seconds and trigger rate 100 kHz
[12:21:57.199] INFO: Done with hot pixel readout
[12:22:11.233] INFO: PixTest:: pg_setup set to default.
[12:22:11.234] INFO: no hot pixel found!
[12:22:11.234] INFO: PixTest::maskHotPixels() done
[12:22:11.237] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-B-3-32_FPIXTest-17C-FNAL-160125-0956_2016-01-25_09h57m_1453737426.2/000_FPIXTest_p17//defaultMaskFile.dat
[12:22:11.408] INFO: enter test to run
[12:23:03.096] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:23:03.096] INFO: running: xray
[12:23:03.097] INFO: ----------------------------------------------------------------------
[12:23:03.097] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:23:03.097] INFO: ----------------------------------------------------------------------
[12:23:04.062] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:23:16.442] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:23:45.674] INFO: Resuming triggers.
[12:23:58.049] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[12:24:26.977] INFO: Resuming triggers.
[12:24:39.356] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[12:25:08.484] INFO: Resuming triggers.
[12:25:20.857] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:25:49.000] INFO: Resuming triggers.
[12:26:02.380] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:26:31.484] INFO: Resuming triggers.
[12:26:43.867] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[12:27:13.007] INFO: Resuming triggers.
[12:27:25.385] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:27:54.645] INFO: Resuming triggers.
[12:28:07.030] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:28:36.117] INFO: Resuming triggers.
[12:28:37.428] INFO: data taking finished, elapsed time: 100 seconds.
[12:28:40.858] INFO: PixTest:: pg_setup set to default.
[12:28:40.861] INFO: PixTestXray::doPhRun() done
[12:28:40.997] INFO: enter test to run
[12:29:01.870] INFO: test: HighRate no parameter change
[12:29:01.870] INFO: running: highrate
[12:29:01.871] INFO: ----------------------------------------------------------------------
[12:29:01.871] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:29:01.871] INFO: ----------------------------------------------------------------------
[12:29:02.011] INFO: Expecting 768 events.
[12:29:03.145] INFO: 768 events read in total (418ms).
[12:29:03.145] INFO: Test took 1268ms.
[12:29:03.948] INFO: Expecting 41600 events.
[12:29:06.903] INFO: 41600 events read in total (2428ms).
[12:29:06.904] INFO: Test took 3751ms.
[12:29:06.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:07.674] INFO: Expecting 41600 events.
[12:29:10.384] INFO: 41600 events read in total (2183ms).
[12:29:10.385] INFO: Test took 3441ms.
[12:29:10.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:11.154] INFO: Expecting 41600 events.
[12:29:14.283] INFO: 41600 events read in total (2602ms).
[12:29:14.284] INFO: Test took 3855ms.
[12:29:14.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:15.045] INFO: Expecting 41600 events.
[12:29:18.210] INFO: 41600 events read in total (2638ms).
[12:29:18.211] INFO: Test took 3884ms.
[12:29:18.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:18.975] INFO: Expecting 41600 events.
[12:29:22.156] INFO: 41600 events read in total (2654ms).
[12:29:22.157] INFO: Test took 3901ms.
[12:29:22.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:22.918] INFO: Expecting 41600 events.
[12:29:26.093] INFO: 41600 events read in total (2649ms).
[12:29:26.094] INFO: Test took 3893ms.
[12:29:26.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:26.856] INFO: Expecting 41600 events.
[12:29:30.032] INFO: 41600 events read in total (2649ms).
[12:29:30.033] INFO: Test took 3895ms.
[12:29:30.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:30.796] INFO: Expecting 41600 events.
[12:29:33.978] INFO: 41600 events read in total (2655ms).
[12:29:33.979] INFO: Test took 3902ms.
[12:29:34.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:34.742] INFO: Expecting 41600 events.
[12:29:37.912] INFO: 41600 events read in total (2643ms).
[12:29:37.913] INFO: Test took 3891ms.
[12:29:37.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:38.673] INFO: Expecting 41600 events.
[12:29:41.852] INFO: 41600 events read in total (2652ms).
[12:29:41.853] INFO: Test took 3893ms.
[12:29:41.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:42.619] INFO: Expecting 41600 events.
[12:29:45.784] INFO: 41600 events read in total (2639ms).
[12:29:45.785] INFO: Test took 3889ms.
[12:29:45.812] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:46.546] INFO: Expecting 41600 events.
[12:29:49.722] INFO: 41600 events read in total (2649ms).
[12:29:49.723] INFO: Test took 3894ms.
[12:29:49.751] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:50.486] INFO: Expecting 41600 events.
[12:29:53.670] INFO: 41600 events read in total (2657ms).
[12:29:53.671] INFO: Test took 3905ms.
[12:29:53.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:54.435] INFO: Expecting 41600 events.
[12:29:57.617] INFO: 41600 events read in total (2655ms).
[12:29:57.618] INFO: Test took 3903ms.
[12:29:57.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:58.381] INFO: Expecting 41600 events.
[12:30:01.545] INFO: 41600 events read in total (2637ms).
[12:30:01.545] INFO: Test took 3884ms.
[12:30:01.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:02.311] INFO: Expecting 41600 events.
[12:30:05.492] INFO: 41600 events read in total (2654ms).
[12:30:05.493] INFO: Test took 3904ms.
[12:30:05.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:06.257] INFO: Expecting 41600 events.
[12:30:09.452] INFO: 41600 events read in total (2668ms).
[12:30:09.453] INFO: Test took 3916ms.
[12:30:09.482] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:10.215] INFO: Expecting 41600 events.
[12:30:13.388] INFO: 41600 events read in total (2646ms).
[12:30:13.389] INFO: Test took 3892ms.
[12:30:13.416] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:14.154] INFO: Expecting 41600 events.
[12:30:17.311] INFO: 41600 events read in total (2630ms).
[12:30:17.312] INFO: Test took 3880ms.
[12:30:17.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:18.078] INFO: Expecting 41600 events.
[12:30:21.101] INFO: 41600 events read in total (2496ms).
[12:30:21.102] INFO: Test took 3746ms.
[12:30:21.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:21.506] INFO: enter test to run
[12:31:08.909] INFO: test: HighRate no parameter change
[12:31:08.909] INFO: running: highrate
[12:31:08.910] INFO: ----------------------------------------------------------------------
[12:31:08.910] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:31:08.910] INFO: ----------------------------------------------------------------------
[12:31:09.537] INFO: Expecting 208000 events.
[12:31:21.080] INFO: 208000 events read in total (11016ms).
[12:31:21.083] INFO: Test took 12154ms.
[12:31:21.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:21.438] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[12:31:21.439] INFO: number of red-efficiency pixels: 45 27 66 80 91 107 117 59 81 79 73 56 86 75 25 22
[12:31:21.439] INFO: number of X-ray hits detected: 47016 24171 60114 72150 82748 98913 102027 60880 61054 73339 67054 51907 78346 47431 21202 21608
[12:31:21.439] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:31:21.439] INFO: number of Vcal hits detected: 207955 207973 207934 207918 207908 207893 207784 207934 207918 207920 207927 207944 207913 207924 207975 207978
[12:31:21.439] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:31:21.439] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:31:21.439] INFO: X-ray hit rate [MHz/cm2]: 13.8 7.1 17.6 21.1 24.3 29.0 29.9 17.8 17.9 21.5 19.7 15.2 23.0 13.9 6.2 6.3
[12:31:21.439] INFO: PixTestHighRate::doXPixelAlive() done
[12:31:21.487] INFO: PixTest:: pg_setup set to default.
[12:31:21.499] INFO: enter test to run
[12:32:09.085] INFO: test: HighRate no parameter change
[12:32:09.085] INFO: running: highrate
[12:32:09.086] INFO: ----------------------------------------------------------------------
[12:32:09.086] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:32:09.086] INFO: ----------------------------------------------------------------------
[12:32:09.720] INFO: Expecting 208000 events.
[12:32:22.333] INFO: 208000 events read in total (12087ms).
[12:32:22.337] INFO: Test took 13243ms.
[12:32:22.549] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:22.820] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[12:32:22.820] INFO: number of red-efficiency pixels: 116 59 186 210 230 274 300 156 189 208 189 114 168 132 41 51
[12:32:22.820] INFO: number of X-ray hits detected: 88047 46496 113516 136854 155365 187105 193411 114853 116346 138379 126631 98107 147345 90094 39702 41558
[12:32:22.820] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:32:22.820] INFO: number of Vcal hits detected: 207883 207941 207808 207786 207760 207718 207586 207832 207802 207781 207800 207882 207826 207864 207958 207949
[12:32:22.820] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[12:32:22.820] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[12:32:22.820] INFO: X-ray hit rate [MHz/cm2]: 25.8 13.6 33.3 40.1 45.5 54.8 56.7 33.7 34.1 40.6 37.1 28.8 43.2 26.4 11.6 12.2
[12:32:22.820] INFO: PixTestHighRate::doXPixelAlive() done
[12:32:22.866] INFO: PixTest:: pg_setup set to default.
[12:32:22.878] INFO: enter test to run
[12:32:53.276] INFO: test: HighRate no parameter change
[12:32:53.276] INFO: running: highrate
[12:32:53.277] INFO: ----------------------------------------------------------------------
[12:32:53.277] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:32:53.277] INFO: ----------------------------------------------------------------------
[12:32:53.896] INFO: Expecting 208000 events.
[12:33:07.412] INFO: 208000 events read in total (12989ms).
[12:33:07.417] INFO: Test took 14130ms.
[12:33:07.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:08.002] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[12:33:08.002] INFO: number of red-efficiency pixels: 179 76 360 395 366 517 489 241 295 310 306 229 330 234 66 73
[12:33:08.002] INFO: number of X-ray hits detected: 121768 64061 155017 188448 215158 256034 266345 157329 159841 188368 173122 135213 202484 123723 54780 57060
[12:33:08.002] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:33:08.002] INFO: number of Vcal hits detected: 207816 207922 207610 207576 207607 207444 207373 207745 207680 207674 207675 207759 207654 207754 207931 207926
[12:33:08.002] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.8 99.8 99.8 99.7 99.8 99.9 99.9 99.9 99.9 99.9 99.8 99.9 100.0 100.0
[12:33:08.002] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.8 99.8 99.8 99.7 99.7 99.9 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[12:33:08.002] INFO: X-ray hit rate [MHz/cm2]: 35.7 18.8 45.4 55.2 63.1 75.0 78.1 46.1 46.9 55.2 50.7 39.6 59.3 36.3 16.1 16.7
[12:33:08.002] INFO: PixTestHighRate::doXPixelAlive() done
[12:33:08.048] INFO: PixTest:: pg_setup set to default.
[12:33:08.067] INFO: enter test to run
[12:33:23.796] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:33:23.796] INFO: running: xray
[12:33:23.797] INFO: ----------------------------------------------------------------------
[12:33:23.797] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:33:23.797] INFO: ----------------------------------------------------------------------
[12:33:24.762] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:33:33.349] INFO: run duration 8 seconds, buffer almost full (81%), pausing triggers.
[12:34:03.252] INFO: Resuming triggers.
[12:34:11.833] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[12:34:41.677] INFO: Resuming triggers.
[12:34:50.260] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:35:20.230] INFO: Resuming triggers.
[12:35:28.800] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:35:58.655] INFO: Resuming triggers.
[12:36:07.221] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:36:37.031] INFO: Resuming triggers.
[12:36:45.597] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:37:15.476] INFO: Resuming triggers.
[12:37:24.035] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:37:53.894] INFO: Resuming triggers.
[12:38:02.451] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:38:32.308] INFO: Resuming triggers.
[12:38:40.867] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:39:10.772] INFO: Resuming triggers.
[12:39:19.329] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:39:49.171] INFO: Resuming triggers.
[12:39:57.737] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:40:27.636] INFO: Resuming triggers.
[12:40:33.723] INFO: data taking finished, elapsed time: 100 seconds.
[12:40:53.353] INFO: PixTest:: pg_setup set to default.
[12:40:53.356] INFO: PixTestXray::doPhRun() done
[12:40:53.503] INFO: enter test to run
[12:40:57.537] INFO: test: exit no parameter change
[12:40:57.873] QUIET: Connection to board 33 closed.
[12:40:57.873] INFO: pXar: this is the end, my friend