[10:49:59.175] INFO: *** Welcome to pxar ***
[10:49:59.175] INFO: *** Today: 2016/04/06
[10:49:59.206] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:49:59.206] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//dacParameters35_C15.dat
[10:49:59.208] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:49:59.208] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//defaultMaskFile.dat
[10:49:59.208] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C15.dat
[10:49:59.310] INFO: clk: 4
[10:49:59.310] INFO: ctr: 4
[10:49:59.310] INFO: sda: 19
[10:49:59.310] INFO: tin: 9
[10:49:59.310] INFO: level: 15
[10:49:59.310] INFO: triggerdelay: 0
[10:49:59.310] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:49:59.310] INFO: Log level: INFO
[10:49:59.327] QUIET: Connection to board DTB_WREKRL opened.
[10:49:59.331] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[10:49:59.334] INFO: RPC call hashes of host and DTB match: 398089610
[10:50:00.860] INFO: DUT info:
[10:50:00.860] INFO: The DUT currently contains the following objects:
[10:50:00.860] INFO: 2 TBM Cores tbm08c (2 ON)
[10:50:00.860] INFO: TBM Core alpha (0): 7 registers set
[10:50:00.860] INFO: TBM Core beta (1): 7 registers set
[10:50:00.860] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:50:00.860] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:00.860] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:50:01.263] INFO: enter 'restricted' command line mode
[10:50:01.263] INFO: enter test to run
[10:50:04.751] INFO: test: PixelAlive no parameter change
[10:50:04.751] INFO: running: pixelalive
[10:50:04.761] INFO: ----------------------------------------------------------------------
[10:50:04.761] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:50:04.761] INFO: ----------------------------------------------------------------------
[10:50:05.078] INFO: Expecting 41600 events.
[10:50:09.389] INFO: 41600 events read in total (3593ms).
[10:50:09.555] INFO: Test took 4791ms.
[10:50:09.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:09.830] INFO: PixTestAlive::aliveTest() done
[10:50:09.830] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:50:09.864] INFO: enter test to run
[10:51:17.158] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:51:17.158] INFO: running: highrate
[10:51:17.159] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:51:17.370] INFO: ----------------------------------------------------------------------
[10:51:17.370] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:51:17.370] INFO: ----------------------------------------------------------------------
[10:51:17.370] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:51:17.370] INFO: edge/corner pixel THR is adjusted
[10:51:17.370] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:51:18.329] INFO: Collecting data for 5 seconds...
[10:51:23.347] INFO: Done with hot pixel readout
[10:51:34.519] INFO: PixTest:: pg_setup set to default.
[10:51:34.520] INFO: 5 hot pixels found in step 0
[10:51:35.535] INFO: Collecting data for 5 seconds...
[10:51:40.552] INFO: Done with hot pixel readout
[10:51:52.022] INFO: PixTest:: pg_setup set to default.
[10:51:52.023] INFO: 9 hot pixels found in step 1
[10:51:53.022] INFO: Collecting data for 5 seconds...
[10:51:58.039] INFO: Done with hot pixel readout
[10:52:09.128] INFO: PixTest:: pg_setup set to default.
[10:52:09.129] INFO: 10 hot pixels found in step 2
[10:52:10.124] INFO: Collecting data for 5 seconds...
[10:52:15.142] INFO: Done with hot pixel readout
[10:52:26.315] INFO: PixTest:: pg_setup set to default.

[10:52:26.316] INFO: 4 hot pixels found in step 3
[10:52:27.317] INFO: Collecting data for 5 seconds...
[10:52:32.332] INFO: Done with hot pixel readout
[10:52:43.511] INFO: PixTest:: pg_setup set to default.
[10:52:43.512] INFO: 3 hot pixels found in step 4
[10:52:44.514] INFO: Collecting data for 5 seconds...
[10:52:49.531] INFO: Done with hot pixel readout
[10:53:00.703] INFO: PixTest:: pg_setup set to default.
[10:53:00.704] INFO: 6 hot pixels found in step 5
[10:53:01.698] INFO: Collecting data for 5 seconds...
[10:53:06.714] INFO: Done with hot pixel readout
[10:53:18.321] INFO: PixTest:: pg_setup set to default.
[10:53:18.322] INFO: 7 hot pixels found in step 6
[10:53:19.316] INFO: Collecting data for 5 seconds...
[10:53:24.324] INFO: Done with hot pixel readout
[10:53:33.661] INFO: PixTest:: pg_setup set to default.
[10:53:33.662] INFO: 6 hot pixels found in step 7
[10:53:34.656] INFO: Collecting data for 5 seconds...
[10:53:39.673] INFO: Done with hot pixel readout
[10:53:51.597] INFO: PixTest:: pg_setup set to default.
[10:53:51.598] INFO: 6 hot pixels found in step 8
[10:53:52.593] INFO: Collecting data for 5 seconds...
[10:53:57.611] INFO: Done with hot pixel readout
[10:54:09.496] INFO: PixTest:: pg_setup set to default.
[10:54:09.497] INFO: 2 hot pixels found in step 9
[10:54:10.492] INFO: Collecting data for 5 seconds...
[10:54:15.509] INFO: Done with hot pixel readout
[10:54:27.368] INFO: PixTest:: pg_setup set to default.

[10:54:27.369] INFO: 10 hot pixels found in step 10
[10:54:28.363] INFO: Collecting data for 5 seconds...
[10:54:33.380] INFO: Done with hot pixel readout
[10:54:45.143] INFO: PixTest:: pg_setup set to default.
[10:54:45.144] INFO: 3 hot pixels found in step 11
[10:54:46.138] INFO: Collecting data for 5 seconds...
[10:54:51.155] INFO: Done with hot pixel readout
[10:55:03.053] INFO: PixTest:: pg_setup set to default.

[10:55:03.054] INFO: 5 hot pixels found in step 12
[10:55:04.047] INFO: Collecting data for 5 seconds...
[10:55:09.063] INFO: Done with hot pixel readout
[10:55:21.023] INFO: PixTest:: pg_setup set to default.
[10:55:21.024] INFO: 5 hot pixels found in step 13
[10:55:22.017] INFO: Collecting data for 5 seconds...
[10:55:27.034] INFO: Done with hot pixel readout
[10:55:38.951] INFO: PixTest:: pg_setup set to default.

[10:55:38.952] INFO: 10 hot pixels found in step 14
[10:55:38.989] INFO: 10 hot pixels could not be trimmed and have been masked.
[10:55:38.993] INFO: PixTest::trimHotPixels() done
[10:55:38.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C0.dat
[10:55:38.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C1.dat
[10:55:39.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C2.dat
[10:55:39.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C3.dat
[10:55:39.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C4.dat
[10:55:39.048] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C5.dat
[10:55:39.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C6.dat
[10:55:39.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C7.dat
[10:55:39.064] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C8.dat
[10:55:39.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C9.dat
[10:55:39.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C10.dat
[10:55:39.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C11.dat
[10:55:39.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C12.dat
[10:55:39.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C13.dat
[10:55:39.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C14.dat
[10:55:39.101] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C15.dat
[10:55:39.106] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//defaultMaskFile.dat
[10:55:39.118] INFO: enter test to run
[10:59:11.323] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:59:11.323] INFO: running: highrate
[10:59:11.328] INFO: ----------------------------------------------------------------------
[10:59:11.328] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:59:11.328] INFO: ----------------------------------------------------------------------
[10:59:11.328] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:59:11.328] INFO: edge/corner pixel THR is adjusted
[10:59:11.328] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:59:12.285] INFO: Collecting data for 1 seconds...
[10:59:13.289] INFO: Done with hot pixel readout
[10:59:17.313] INFO: PixTest:: pg_setup set to default.
[10:59:17.314] INFO: 0 hot pixels found in step 0
[10:59:17.320] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:59:17.405] INFO: PixTest::trimHotPixels() done
[10:59:17.405] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C0.dat
[10:59:17.417] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C1.dat
[10:59:17.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C2.dat
[10:59:17.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C3.dat
[10:59:17.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C4.dat
[10:59:17.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C5.dat
[10:59:17.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C6.dat
[10:59:17.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C7.dat
[10:59:17.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C8.dat
[10:59:17.466] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C9.dat
[10:59:17.471] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C10.dat
[10:59:17.476] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C11.dat
[10:59:17.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C12.dat
[10:59:17.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C13.dat
[10:59:17.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C14.dat
[10:59:17.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C15.dat
[10:59:17.502] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-43_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//defaultMaskFile.dat
[10:59:17.511] INFO: enter test to run
[10:59:45.682] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:59:45.682] INFO: running: xray
[10:59:45.683] INFO: ----------------------------------------------------------------------
[10:59:45.683] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:59:45.683] INFO: ----------------------------------------------------------------------
[10:59:46.647] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:59:57.962] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:00:27.291] INFO: Resuming triggers.
[11:00:38.609] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:01:08.233] INFO: Resuming triggers.
[11:01:19.549] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:01:49.066] INFO: Resuming triggers.
[11:02:00.384] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:02:27.777] INFO: Resuming triggers.
[11:02:39.089] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:03:08.397] INFO: Resuming triggers.
[11:03:19.712] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[11:03:44.332] INFO: Resuming triggers.
[11:03:55.644] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[11:04:23.889] INFO: Resuming triggers.
[11:04:35.206] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[11:05:01.031] INFO: Resuming triggers.
[11:05:10.825] INFO: data taking finished, elapsed time: 100 seconds.
[11:05:35.658] INFO: PixTest:: pg_setup set to default.
[11:05:35.662] INFO: PixTestXray::doPhRun() done
[11:05:35.846] INFO: enter test to run
[11:06:49.759] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:06:49.759] INFO: running: xray
[11:06:49.760] INFO: ----------------------------------------------------------------------
[11:06:49.760] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:06:49.761] INFO: ----------------------------------------------------------------------
[11:06:50.734] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:06:57.354] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:07:27.313] INFO: Resuming triggers.
[11:07:33.936] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:08:03.876] INFO: Resuming triggers.
[11:08:10.501] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:08:40.508] INFO: Resuming triggers.
[11:08:47.132] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:09:17.144] INFO: Resuming triggers.
[11:09:23.768] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:09:53.776] INFO: Resuming triggers.
[11:10:00.400] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:10:30.515] INFO: Resuming triggers.
[11:10:37.136] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:11:07.351] INFO: Resuming triggers.
[11:11:13.974] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[11:11:43.642] INFO: Resuming triggers.
[11:11:50.261] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:12:20.383] INFO: Resuming triggers.
[11:12:26.005] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[11:12:57.153] INFO: Resuming triggers.
[11:13:03.772] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[11:13:34.238] INFO: Resuming triggers.
[11:13:40.856] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:14:09.579] INFO: Resuming triggers.
[11:14:16.198] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[11:14:43.507] INFO: Resuming triggers.
[11:14:50.126] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[11:15:19.991] INFO: Resuming triggers.
[11:15:26.613] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[11:15:56.761] INFO: Resuming triggers.
[11:15:57.765] INFO: data taking finished, elapsed time: 100 seconds.
[11:16:02.611] INFO: PixTest:: pg_setup set to default.
[11:16:02.614] INFO: PixTestXray::doPhRun() done
[11:16:02.771] INFO: enter test to run
[11:17:34.146] INFO: test: HighRate no parameter change
[11:17:34.147] INFO: running: highrate
[11:17:34.148] INFO: ----------------------------------------------------------------------
[11:17:34.148] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:17:34.148] INFO: ----------------------------------------------------------------------
[11:17:34.290] INFO: Expecting 768 events.
[11:17:35.424] INFO: 768 events read in total (419ms).
[11:17:35.424] INFO: Test took 1270ms.
[11:17:36.227] INFO: Expecting 41600 events.
[11:17:39.267] INFO: 41600 events read in total (2513ms).
[11:17:39.268] INFO: Test took 3837ms.
[11:17:39.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:40.029] INFO: Expecting 41600 events.
[11:17:43.238] INFO: 41600 events read in total (2682ms).
[11:17:43.239] INFO: Test took 3919ms.
[11:17:43.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:43.994] INFO: Expecting 41600 events.
[11:17:47.258] INFO: 41600 events read in total (2737ms).
[11:17:47.259] INFO: Test took 3966ms.
[11:17:47.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:48.014] INFO: Expecting 41600 events.
[11:17:51.257] INFO: 41600 events read in total (2717ms).
[11:17:51.258] INFO: Test took 3945ms.
[11:17:51.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:52.016] INFO: Expecting 41600 events.
[11:17:55.277] INFO: 41600 events read in total (2734ms).
[11:17:55.277] INFO: Test took 3965ms.
[11:17:55.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:56.034] INFO: Expecting 41600 events.
[11:17:59.263] INFO: 41600 events read in total (2702ms).
[11:17:59.264] INFO: Test took 3932ms.
[11:17:59.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:00.023] INFO: Expecting 41600 events.
[11:18:03.258] INFO: 41600 events read in total (2708ms).
[11:18:03.259] INFO: Test took 3942ms.
[11:18:03.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:04.017] INFO: Expecting 41600 events.
[11:18:07.213] INFO: 41600 events read in total (2669ms).
[11:18:07.214] INFO: Test took 3900ms.
[11:18:07.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:07.969] INFO: Expecting 41600 events.
[11:18:11.214] INFO: 41600 events read in total (2719ms).
[11:18:11.215] INFO: Test took 3947ms.
[11:18:11.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:11.973] INFO: Expecting 41600 events.
[11:18:15.184] INFO: 41600 events read in total (2685ms).
[11:18:15.185] INFO: Test took 3915ms.
[11:18:15.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:15.941] INFO: Expecting 41600 events.
[11:18:19.172] INFO: 41600 events read in total (2704ms).
[11:18:19.173] INFO: Test took 3935ms.
[11:18:19.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:19.932] INFO: Expecting 41600 events.
[11:18:23.151] INFO: 41600 events read in total (2692ms).
[11:18:23.153] INFO: Test took 3926ms.
[11:18:23.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:23.907] INFO: Expecting 41600 events.
[11:18:27.147] INFO: 41600 events read in total (2713ms).
[11:18:27.148] INFO: Test took 3940ms.
[11:18:27.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:27.904] INFO: Expecting 41600 events.
[11:18:31.135] INFO: 41600 events read in total (2704ms).
[11:18:31.136] INFO: Test took 3933ms.
[11:18:31.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:31.895] INFO: Expecting 41600 events.
[11:18:35.140] INFO: 41600 events read in total (2718ms).
[11:18:35.141] INFO: Test took 3951ms.
[11:18:35.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:35.897] INFO: Expecting 41600 events.
[11:18:39.125] INFO: 41600 events read in total (2701ms).
[11:18:39.126] INFO: Test took 3930ms.
[11:18:39.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:39.883] INFO: Expecting 41600 events.
[11:18:43.144] INFO: 41600 events read in total (2734ms).
[11:18:43.145] INFO: Test took 3967ms.
[11:18:43.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:43.900] INFO: Expecting 41600 events.
[11:18:47.129] INFO: 41600 events read in total (2702ms).
[11:18:47.130] INFO: Test took 3930ms.
[11:18:47.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:47.888] INFO: Expecting 41600 events.
[11:18:51.110] INFO: 41600 events read in total (2695ms).
[11:18:51.111] INFO: Test took 3926ms.
[11:18:51.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:51.868] INFO: Expecting 41600 events.
[11:18:54.929] INFO: 41600 events read in total (2534ms).
[11:18:54.930] INFO: Test took 3764ms.
[11:18:54.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:55.332] INFO: enter test to run
[11:20:05.825] INFO: test: HighRate no parameter change
[11:20:05.825] INFO: running: highrate
[11:20:05.827] INFO: ----------------------------------------------------------------------
[11:20:05.827] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:20:05.827] INFO: ----------------------------------------------------------------------
[11:20:06.444] INFO: Expecting 208000 events.
[11:20:18.345] INFO: 208000 events read in total (11374ms).
[11:20:18.348] INFO: Test took 12512ms.
[11:20:18.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:18.747] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:20:18.748] INFO: number of red-efficiency pixels: 95 48 98 158 152 184 153 132 116 136 132 121 98 59 20 24
[11:20:18.748] INFO: number of X-ray hits detected: 66978 45039 73845 115716 120339 122847 120326 85497 76216 103513 100689 84638 86049 51702 23196 25039
[11:20:18.748] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:20:18.748] INFO: number of Vcal hits detected: 207903 207949 207851 207835 207845 207808 207833 207866 207882 207862 207863 207874 207901 207939 207980 207976
[11:20:18.748] 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 100.0 100.0 100.0 100.0
[11:20:18.748] INFO: Vcal hit overall efficiency (%): 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 100.0
[11:20:18.748] INFO: X-ray hit rate [MHz/cm2]: 19.6 13.2 21.6 33.9 35.3 36.0 35.3 25.1 22.3 30.3 29.5 24.8 25.2 15.2 6.8 7.3
[11:20:18.748] INFO: PixTestHighRate::doXPixelAlive() done
[11:20:18.798] INFO: PixTest:: pg_setup set to default.
[11:20:18.812] INFO: enter test to run
[11:20:41.281] INFO: test: HighRate no parameter change
[11:20:41.281] INFO: running: highrate
[11:20:41.282] INFO: ----------------------------------------------------------------------
[11:20:41.282] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:20:41.282] INFO: ----------------------------------------------------------------------
[11:20:41.895] INFO: Expecting 208000 events.
[11:20:55.672] INFO: 208000 events read in total (13250ms).
[11:20:55.677] INFO: Test took 14384ms.
[11:20:55.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:56.282] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:20:56.282] INFO: number of red-efficiency pixels: 233 148 375 543 475 657 466 335 351 427 333 288 259 181 60 53
[11:20:56.282] INFO: number of X-ray hits detected: 139266 93702 154352 237870 248348 255322 247032 177065 157222 214082 209290 175760 178163 107213 48189 52638
[11:20:56.282] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:20:56.282] INFO: number of Vcal hits detected: 207756 207845 207525 207379 207497 207250 207464 207636 207627 207536 207651 207697 207735 207802 207940 207947
[11:20:56.282] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:20:56.282] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.6 99.7 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:20:56.282] INFO: X-ray hit rate [MHz/cm2]: 40.8 27.5 45.2 69.7 72.8 74.8 72.4 51.9 46.1 62.7 61.3 51.5 52.2 31.4 14.1 15.4
[11:20:56.282] INFO: PixTestHighRate::doXPixelAlive() done
[11:20:56.327] INFO: PixTest:: pg_setup set to default.
[11:20:56.339] INFO: enter test to run
[11:21:35.737] INFO: test: HighRate no parameter change
[11:21:35.737] INFO: running: highrate
[11:21:35.738] INFO: ----------------------------------------------------------------------
[11:21:35.738] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:21:35.738] INFO: ----------------------------------------------------------------------
[11:21:36.353] INFO: Expecting 208000 events.
[11:21:51.888] INFO: 208000 events read in total (15008ms).
[11:21:51.895] INFO: Test took 16147ms.
[11:21:52.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:52.675] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:21:52.675] INFO: number of red-efficiency pixels: 478 298 801 1263 969 1397 1078 654 672 969 709 539 574 440 121 110
[11:21:52.675] INFO: number of X-ray hits detected: 203122 137817 224437 346632 363686 374178 362556 258801 229833 311832 305092 257604 261904 157637 71240 77190
[11:21:52.675] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:21:52.675] INFO: number of Vcal hits detected: 207465 207668 206860 206350 206827 206100 206615 207182 207208 206806 207200 207401 207366 207494 207872 207886
[11:21:52.675] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.5 99.3 99.5 99.2 99.4 99.6 99.7 99.5 99.6 99.7 99.7 99.8 99.9 99.9
[11:21:52.675] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.2 99.4 99.1 99.3 99.6 99.6 99.4 99.6 99.7 99.7 99.8 99.9 99.9
[11:21:52.675] INFO: X-ray hit rate [MHz/cm2]: 59.5 40.4 65.8 101.6 106.6 109.7 106.3 75.9 67.4 91.4 89.4 75.5 76.8 46.2 20.9 22.6
[11:21:52.675] INFO: PixTestHighRate::doXPixelAlive() done
[11:21:52.723] INFO: PixTest:: pg_setup set to default.
[11:21:52.738] INFO: enter test to run
[11:22:34.960] INFO: test: exit no parameter change
[11:22:35.254] QUIET: Connection to board 33 closed.
[11:22:35.255] INFO: pXar: this is the end, my friend