[09:16:06.000] INFO: *** Welcome to pxar ***
[09:16:06.000] INFO: *** Today: 2016/04/05
[09:16:07.048] INFO: *** Version: v1.9.0-793-ge521-dirty
[09:16:07.048] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/dacParameters35_C15.dat
[09:16:07.051] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/tbmParameters_C0b.dat
[09:16:07.051] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/defaultMaskFile.dat
[09:16:07.052] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C15.dat
[09:16:07.158] INFO: clk: 4
[09:16:07.158] INFO: ctr: 4
[09:16:07.158] INFO: sda: 19
[09:16:07.158] INFO: tin: 9
[09:16:07.158] INFO: level: 15
[09:16:07.158] INFO: triggerdelay: 0
[09:16:07.158] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[09:16:07.158] INFO: Log level: INFO
[09:16:07.176] QUIET: Connection to board DTB_WREKRL opened.
[09:16:07.180] 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:
------------------------------------------------------
[09:16:07.182] INFO: RPC call hashes of host and DTB match: 398089610
[09:16:08.717] INFO: DUT info:
[09:16:08.717] INFO: The DUT currently contains the following objects:
[09:16:08.717] INFO: 2 TBM Cores tbm08c (2 ON)
[09:16:08.717] INFO: TBM Core alpha (0): 7 registers set
[09:16:08.717] INFO: TBM Core beta (1): 7 registers set
[09:16:08.717] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:16:08.718] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:08.718] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:16:09.122] INFO: enter 'restricted' command line mode
[09:16:09.122] INFO: enter test to run
[09:16:45.144] INFO: test: PixelAlive no parameter change
[09:16:45.144] INFO: running: pixelalive
[09:16:45.154] INFO: ----------------------------------------------------------------------
[09:16:45.154] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:16:45.154] INFO: ----------------------------------------------------------------------
[09:16:45.476] INFO: Expecting 41600 events.
[09:16:49.808] INFO: 41600 events read in total (3614ms).
[09:16:49.978] INFO: Test took 4822ms.
[09:16:49.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:50.250] INFO: PixTestAlive::aliveTest() done
[09:16:50.250] INFO: number of dead pixels (per ROC): 0 0 2 1 0 0 0 0 0 0 0 0 0 0 0 0
[09:16:50.282] INFO: enter test to run
[09:18:16.976] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:18:16.976] INFO: running: highrate
[09:18:16.976] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/phCalibrationFitErr35_C15.dat
[09:18:17.187] INFO: ----------------------------------------------------------------------
[09:18:17.187] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:18:17.187] INFO: ----------------------------------------------------------------------
[09:18:17.187] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:18:17.187] INFO: edge/corner pixel THR is adjusted
[09:18:17.187] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:18:18.146] INFO: Collecting data for 5 seconds...
[09:18:23.162] INFO: Done with hot pixel readout
[09:18:35.794] INFO: PixTest:: pg_setup set to default.


[09:18:35.795] INFO: 129 hot pixels found in step 0
[09:18:36.790] INFO: Collecting data for 5 seconds...
[09:18:41.807] INFO: Done with hot pixel readout
[09:18:54.420] INFO: PixTest:: pg_setup set to default.



[09:18:54.421] INFO: 113 hot pixels found in step 1
[09:18:55.420] INFO: Collecting data for 5 seconds...
[09:19:00.437] INFO: Done with hot pixel readout
[09:19:09.907] INFO: PixTest:: pg_setup set to default.





[09:19:09.908] INFO: 101 hot pixels found in step 2
[09:19:10.906] INFO: Collecting data for 5 seconds...
[09:19:15.918] INFO: Done with hot pixel readout
[09:19:28.431] INFO: PixTest:: pg_setup set to default.







[09:19:28.432] INFO: 106 hot pixels found in step 3
[09:19:29.430] INFO: Collecting data for 5 seconds...
[09:19:34.448] INFO: Done with hot pixel readout
[09:19:46.997] INFO: PixTest:: pg_setup set to default.





[09:19:46.999] INFO: 91 hot pixels found in step 4
[09:19:47.996] INFO: Collecting data for 5 seconds...
[09:19:53.013] INFO: Done with hot pixel readout
[09:20:05.601] INFO: PixTest:: pg_setup set to default.










[09:20:05.603] INFO: 93 hot pixels found in step 5
[09:20:06.600] INFO: Collecting data for 5 seconds...
[09:20:11.616] INFO: Done with hot pixel readout
[09:20:24.190] INFO: PixTest:: pg_setup set to default.






[09:20:24.191] INFO: 78 hot pixels found in step 6
[09:20:25.189] INFO: Collecting data for 5 seconds...
[09:20:30.205] INFO: Done with hot pixel readout
[09:20:42.816] INFO: PixTest:: pg_setup set to default.






[09:20:42.817] INFO: 67 hot pixels found in step 7
[09:20:43.814] INFO: Collecting data for 5 seconds...
[09:20:48.831] INFO: Done with hot pixel readout
[09:21:01.406] INFO: PixTest:: pg_setup set to default.







[09:21:01.407] INFO: 96 hot pixels found in step 8
[09:21:02.405] INFO: Collecting data for 5 seconds...
[09:21:07.422] INFO: Done with hot pixel readout
[09:21:19.980] INFO: PixTest:: pg_setup set to default.




[09:21:19.982] INFO: 76 hot pixels found in step 9
[09:21:20.980] INFO: Collecting data for 5 seconds...
[09:21:25.998] INFO: Done with hot pixel readout
[09:21:38.569] INFO: PixTest:: pg_setup set to default.










[09:21:38.570] INFO: 57 hot pixels found in step 10
[09:21:39.567] INFO: Collecting data for 5 seconds...
[09:21:44.582] INFO: Done with hot pixel readout
[09:21:57.156] INFO: PixTest:: pg_setup set to default.















[09:21:57.157] INFO: 63 hot pixels found in step 11
[09:21:58.154] INFO: Collecting data for 5 seconds...
[09:22:03.170] INFO: Done with hot pixel readout
[09:22:15.754] INFO: PixTest:: pg_setup set to default.




[09:22:15.755] INFO: 55 hot pixels found in step 12
[09:22:16.753] INFO: Collecting data for 5 seconds...
[09:22:21.770] INFO: Done with hot pixel readout
[09:22:34.390] INFO: PixTest:: pg_setup set to default.








[09:22:34.391] INFO: 55 hot pixels found in step 13
[09:22:35.389] INFO: Collecting data for 5 seconds...
[09:22:40.405] INFO: Done with hot pixel readout
[09:22:52.979] INFO: PixTest:: pg_setup set to default.











[09:22:52.980] INFO: 55 hot pixels found in step 14
[09:22:53.021] INFO: 55 hot pixels could not be trimmed and have been masked.
[09:22:53.025] INFO: PixTest::trimHotPixels() done
[09:22:53.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C0.dat
[09:22:53.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C1.dat
[09:22:53.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C2.dat
[09:22:53.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C3.dat
[09:22:53.048] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C4.dat
[09:22:53.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C5.dat
[09:22:53.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C6.dat
[09:22:53.064] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C7.dat
[09:22:53.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C8.dat
[09:22:53.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C9.dat
[09:22:53.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C10.dat
[09:22:53.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C11.dat
[09:22:53.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C12.dat
[09:22:53.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C13.dat
[09:22:53.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C14.dat
[09:22:53.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C15.dat
[09:22:53.111] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/defaultMaskFile.dat
[09:22:53.121] INFO: enter test to run
[09:23:34.669] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:23:34.670] INFO: running: highrate
[09:23:34.674] INFO: ----------------------------------------------------------------------
[09:23:34.674] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:23:34.674] INFO: ----------------------------------------------------------------------
[09:23:34.674] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:23:34.674] INFO: edge/corner pixel THR is adjusted
[09:23:34.674] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:23:35.632] INFO: Collecting data for 1 seconds...
[09:23:36.635] INFO: Done with hot pixel readout
[09:23:41.059] INFO: PixTest:: pg_setup set to default.
[09:23:41.060] INFO: 0 hot pixels found in step 0
[09:23:41.065] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:23:41.138] INFO: PixTest::trimHotPixels() done
[09:23:41.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C0.dat
[09:23:41.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C1.dat
[09:23:41.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C2.dat
[09:23:41.163] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C3.dat
[09:23:41.168] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C4.dat
[09:23:41.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C5.dat
[09:23:41.179] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C6.dat
[09:23:41.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C7.dat
[09:23:41.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C8.dat
[09:23:41.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C9.dat
[09:23:41.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C10.dat
[09:23:41.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C11.dat
[09:23:41.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C12.dat
[09:23:41.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C13.dat
[09:23:41.220] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C14.dat
[09:23:41.225] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/trimParameters35_C15.dat
[09:23:41.231] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-49_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17/defaultMaskFile.dat
[09:23:41.241] INFO: enter test to run
[09:24:51.133] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:24:51.133] INFO: running: xray
[09:24:51.134] INFO: ----------------------------------------------------------------------
[09:24:51.134] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:24:51.134] INFO: ----------------------------------------------------------------------
[09:24:52.098] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:25:02.784] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[09:25:32.494] INFO: Resuming triggers.
[09:25:43.186] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[09:26:13.017] INFO: Resuming triggers.
[09:26:23.703] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:26:53.521] INFO: Resuming triggers.
[09:27:04.205] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[09:27:33.922] INFO: Resuming triggers.
[09:27:44.609] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[09:28:14.406] INFO: Resuming triggers.
[09:28:25.086] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[09:28:54.765] INFO: Resuming triggers.
[09:29:05.447] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:29:30.103] INFO: Resuming triggers.
[09:29:40.784] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[09:30:10.425] INFO: Resuming triggers.
[09:30:21.114] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[09:30:50.849] INFO: Resuming triggers.
[09:30:55.025] INFO: data taking finished, elapsed time: 100 seconds.
[09:31:06.910] INFO: PixTest:: pg_setup set to default.
[09:31:06.913] INFO: PixTestXray::doPhRun() done
[09:31:07.051] INFO: enter test to run
[09:32:33.113] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:32:33.113] INFO: running: xray
[09:32:33.115] INFO: ----------------------------------------------------------------------
[09:32:33.115] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:32:33.115] INFO: ----------------------------------------------------------------------
[09:32:34.083] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:32:39.983] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[09:33:10.219] INFO: Resuming triggers.
[09:33:16.123] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:33:46.146] INFO: Resuming triggers.
[09:33:52.046] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[09:34:22.282] INFO: Resuming triggers.
[09:34:28.186] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:34:58.338] INFO: Resuming triggers.
[09:35:04.244] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[09:35:34.437] INFO: Resuming triggers.
[09:35:40.342] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[09:36:10.437] INFO: Resuming triggers.
[09:36:16.337] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[09:36:46.495] INFO: Resuming triggers.
[09:36:52.390] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[09:37:22.621] INFO: Resuming triggers.
[09:37:28.523] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[09:37:58.706] INFO: Resuming triggers.
[09:38:04.604] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:38:34.738] INFO: Resuming triggers.
[09:38:40.639] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[09:39:10.798] INFO: Resuming triggers.
[09:39:16.700] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[09:39:44.632] INFO: Resuming triggers.
[09:39:50.526] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[09:40:20.621] INFO: Resuming triggers.
[09:40:26.514] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[09:40:56.741] INFO: Resuming triggers.
[09:41:02.638] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[09:41:32.865] INFO: Resuming triggers.
[09:41:38.762] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[09:42:08.903] INFO: Resuming triggers.
[09:42:14.799] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[09:42:44.963] INFO: Resuming triggers.
[09:42:44.997] INFO: data taking finished, elapsed time: 100 seconds.
[09:42:45.709] INFO: PixTest:: pg_setup set to default.
[09:42:45.712] INFO: PixTestXray::doPhRun() done
[09:42:45.868] INFO: enter test to run
[09:44:38.956] INFO: test: HighRate no parameter change
[09:44:38.956] INFO: running: highrate
[09:44:38.957] INFO: ----------------------------------------------------------------------
[09:44:38.957] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:44:38.957] INFO: ----------------------------------------------------------------------
[09:44:39.099] INFO: Expecting 768 events.
[09:44:40.231] INFO: 768 events read in total (416ms).
[09:44:40.232] INFO: Test took 1267ms.
[09:44:41.035] INFO: Expecting 41600 events.
[09:44:44.189] INFO: 41600 events read in total (2627ms).
[09:44:44.190] INFO: Test took 3950ms.
[09:44:44.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:44.945] INFO: Expecting 41600 events.
[09:44:48.217] INFO: 41600 events read in total (2745ms).
[09:44:48.218] INFO: Test took 3967ms.
[09:44:48.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:48.971] INFO: Expecting 41600 events.
[09:44:52.259] INFO: 41600 events read in total (2761ms).
[09:44:52.261] INFO: Test took 3980ms.
[09:44:52.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:53.013] INFO: Expecting 41600 events.
[09:44:56.325] INFO: 41600 events read in total (2785ms).
[09:44:56.326] INFO: Test took 4004ms.
[09:44:56.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:57.073] INFO: Expecting 41600 events.
[09:45:00.386] INFO: 41600 events read in total (2786ms).
[09:45:00.387] INFO: Test took 3999ms.
[09:45:00.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:01.141] INFO: Expecting 41600 events.
[09:45:04.451] INFO: 41600 events read in total (2783ms).
[09:45:04.452] INFO: Test took 4002ms.
[09:45:04.495] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:05.203] INFO: Expecting 41600 events.
[09:45:08.506] INFO: 41600 events read in total (2776ms).
[09:45:08.507] INFO: Test took 3992ms.
[09:45:08.550] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:09.257] INFO: Expecting 41600 events.
[09:45:12.573] INFO: 41600 events read in total (2789ms).
[09:45:12.574] INFO: Test took 4003ms.
[09:45:12.615] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:13.323] INFO: Expecting 41600 events.
[09:45:16.641] INFO: 41600 events read in total (2791ms).
[09:45:16.642] INFO: Test took 4006ms.
[09:45:16.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:17.392] INFO: Expecting 41600 events.
[09:45:20.698] INFO: 41600 events read in total (2779ms).
[09:45:20.699] INFO: Test took 3995ms.
[09:45:20.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:21.450] INFO: Expecting 41600 events.
[09:45:24.765] INFO: 41600 events read in total (2788ms).
[09:45:24.767] INFO: Test took 4006ms.
[09:45:24.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:25.517] INFO: Expecting 41600 events.
[09:45:28.835] INFO: 41600 events read in total (2791ms).
[09:45:28.836] INFO: Test took 4008ms.
[09:45:28.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:29.586] INFO: Expecting 41600 events.
[09:45:32.913] INFO: 41600 events read in total (2800ms).
[09:45:32.914] INFO: Test took 4015ms.
[09:45:32.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:33.664] INFO: Expecting 41600 events.
[09:45:36.996] INFO: 41600 events read in total (2805ms).
[09:45:36.997] INFO: Test took 4019ms.
[09:45:37.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:37.750] INFO: Expecting 41600 events.
[09:45:41.073] INFO: 41600 events read in total (2796ms).
[09:45:41.074] INFO: Test took 4014ms.
[09:45:41.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:41.824] INFO: Expecting 41600 events.
[09:45:45.142] INFO: 41600 events read in total (2791ms).
[09:45:45.143] INFO: Test took 4007ms.
[09:45:45.184] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:45.894] INFO: Expecting 41600 events.
[09:45:49.214] INFO: 41600 events read in total (2793ms).
[09:45:49.215] INFO: Test took 4011ms.
[09:45:49.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:49.967] INFO: Expecting 41600 events.
[09:45:53.293] INFO: 41600 events read in total (2799ms).
[09:45:53.294] INFO: Test took 3993ms.
[09:45:53.335] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:54.047] INFO: Expecting 41600 events.
[09:45:57.355] INFO: 41600 events read in total (2782ms).
[09:45:57.356] INFO: Test took 3999ms.
[09:45:57.397] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:58.105] INFO: Expecting 41600 events.
[09:46:01.306] INFO: 41600 events read in total (2674ms).
[09:46:01.307] INFO: Test took 3888ms.
[09:46:01.347] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:01.698] INFO: enter test to run
[09:47:58.235] INFO: test: HighRate no parameter change
[09:47:58.235] INFO: running: highrate
[09:47:58.236] INFO: ----------------------------------------------------------------------
[09:47:58.236] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:47:58.236] INFO: ----------------------------------------------------------------------
[09:47:58.857] INFO: Expecting 208000 events.
[09:48:11.120] INFO: 208000 events read in total (11736ms).
[09:48:11.124] INFO: Test took 12880ms.
[09:48:11.306] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:11.570] INFO: number of dead pixels (per ROC): 0 0 3 1 0 0 0 0 0 0 0 0 0 0 0 0
[09:48:11.570] INFO: number of red-efficiency pixels: 106 51 116 150 245 188 181 115 163 192 150 148 161 86 21 29
[09:48:11.570] INFO: number of X-ray hits detected: 84737 53010 85206 131165 145629 147877 151525 109007 105789 125502 126425 105682 105680 65971 28284 31760
[09:48:11.570] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:48:11.571] INFO: number of Vcal hits detected: 207891 207946 207732 207752 207747 207807 207809 207880 207834 207804 207842 207847 207836 207913 207979 207969
[09:48:11.571] INFO: Vcal hit fiducial 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 99.9 100.0 100.0 100.0
[09:48:11.571] INFO: Vcal hit overall 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 100.0 100.0 100.0
[09:48:11.571] INFO: X-ray hit rate [MHz/cm2]: 24.8 15.5 25.0 38.4 42.7 43.3 44.4 32.0 31.0 36.8 37.1 31.0 31.0 19.3 8.3 9.3
[09:48:11.571] INFO: PixTestHighRate::doXPixelAlive() done
[09:48:11.617] INFO: PixTest:: pg_setup set to default.
[09:48:11.634] INFO: enter test to run
[09:49:45.362] INFO: test: HighRate no parameter change
[09:49:45.362] INFO: running: highrate
[09:49:45.363] INFO: ----------------------------------------------------------------------
[09:49:45.363] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:49:45.363] INFO: ----------------------------------------------------------------------
[09:49:45.984] INFO: Expecting 208000 events.
[09:50:00.440] INFO: 208000 events read in total (13929ms).
[09:50:00.447] INFO: Test took 15073ms.
[09:50:00.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:01.137] INFO: number of dead pixels (per ROC): 0 0 3 1 0 0 0 0 0 0 0 0 0 0 0 0
[09:50:01.137] INFO: number of red-efficiency pixels: 290 174 381 507 835 617 605 428 420 637 471 495 483 256 73 57
[09:50:01.137] INFO: number of X-ray hits detected: 168683 105060 170214 260159 290038 293443 301900 217280 211635 249370 251108 211541 212504 131470 57340 63529
[09:50:01.137] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:50:01.137] INFO: number of Vcal hits detected: 207697 207819 207416 207348 207036 207295 207291 207535 207547 207277 207491 207450 207486 207723 207922 207943
[09:50:01.137] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.7 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[09:50:01.137] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.7 99.5 99.7 99.7 99.8 99.8 99.7 99.8 99.7 99.8 99.9 100.0 100.0
[09:50:01.137] INFO: X-ray hit rate [MHz/cm2]: 49.4 30.8 49.9 76.3 85.0 86.0 88.5 63.7 62.0 73.1 73.6 62.0 62.3 38.5 16.8 18.6
[09:50:01.137] INFO: PixTestHighRate::doXPixelAlive() done
[09:50:01.183] INFO: PixTest:: pg_setup set to default.
[09:50:01.198] INFO: enter test to run
[09:51:01.537] INFO: test: HighRate no parameter change
[09:51:01.537] INFO: running: highrate
[09:51:01.538] INFO: ----------------------------------------------------------------------
[09:51:01.538] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:51:01.538] INFO: ----------------------------------------------------------------------
[09:51:02.151] INFO: Expecting 208000 events.
[09:51:19.017] INFO: 208000 events read in total (16339ms).
[09:51:19.025] INFO: Test took 17476ms.
[09:51:19.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:19.964] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:51:19.964] INFO: number of red-efficiency pixels: 524 363 769 1141 1834 1432 1462 870 1037 1438 1106 1039 1014 533 97 91
[09:51:19.964] INFO: number of X-ray hits detected: 252654 156112 253770 389437 430002 436835 449027 325284 315953 374989 375655 315921 315864 197453 86402 94730
[09:51:19.964] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:51:19.964] INFO: number of Vcal hits detected: 207371 207598 206699 206430 205233 206039 205948 206887 206685 206084 206566 206664 206740 207351 207900 207903
[09:51:19.964] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.3 98.8 99.2 99.1 99.5 99.4 99.2 99.4 99.4 99.5 99.7 100.0 100.0
[09:51:19.964] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.4 99.2 98.7 99.1 99.0 99.5 99.4 99.1 99.3 99.4 99.4 99.7 100.0 100.0
[09:51:19.964] INFO: X-ray hit rate [MHz/cm2]: 74.1 45.8 74.4 114.1 126.0 128.0 131.6 95.3 92.6 109.9 110.1 92.6 92.6 57.9 25.3 27.8
[09:51:19.964] INFO: PixTestHighRate::doXPixelAlive() done
[09:51:20.016] INFO: PixTest:: pg_setup set to default.
[09:51:20.036] INFO: enter test to run
[09:51:23.833] INFO: test: exit no parameter change
[09:51:24.166] QUIET: Connection to board 33 closed.
[09:51:24.167] INFO: pXar: this is the end, my friend