[20:50:51.352] INFO: *** Welcome to pxar ***
[20:50:51.352] INFO: *** Today: 2016/08/14
[20:50:51.370] INFO: *** Version: v1.9.0-818-g96727
[20:50:51.370] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//dacParameters35_C15.dat
[20:50:51.409] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//tbmParameters_C0b.dat
[20:50:51.409] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//defaultMaskFile.dat
[20:50:51.409] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C15.dat
[20:50:51.586] INFO: clk: 4
[20:50:51.586] INFO: ctr: 4
[20:50:51.586] INFO: sda: 19
[20:50:51.586] INFO: tin: 9
[20:50:51.586] INFO: level: 15
[20:50:51.586] INFO: triggerdelay: 0
[20:50:51.586] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[20:50:51.586] INFO: Log level: INFO
[20:50:51.604] QUIET: Connection to board DTB_WREKRL opened.
[20:50:51.608] 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:
------------------------------------------------------
[20:50:51.610] INFO: RPC call hashes of host and DTB match: 398089610
[20:50:53.143] INFO: DUT info:
[20:50:53.144] INFO: The DUT currently contains the following objects:
[20:50:53.144] INFO: 2 TBM Cores tbm08c (2 ON)
[20:50:53.144] INFO: TBM Core alpha (0): 7 registers set
[20:50:53.144] INFO: TBM Core beta (1): 7 registers set
[20:50:53.144] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[20:50:53.144] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.144] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[20:50:53.554] INFO: enter 'restricted' command line mode
[20:50:53.554] INFO: enter test to run
[20:50:56.376] INFO: test: PixelAlive no parameter change
[20:50:56.376] INFO: running: pixelalive
[20:50:56.385] INFO: ----------------------------------------------------------------------
[20:50:56.385] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[20:50:56.385] INFO: ----------------------------------------------------------------------
[20:50:56.706] INFO: Expecting 41600 events.
[20:51:01.047] INFO: 41600 events read in total (3623ms).
[20:51:01.216] INFO: Test took 4828ms.
[20:51:01.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:51:01.516] INFO: PixTestAlive::aliveTest() done
[20:51:01.516] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 29 189 73 51 3 0 0 0 0
[20:51:01.547] INFO: enter test to run
[20:51:19.904] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[20:51:19.904] INFO: running: highrate
[20:51:19.904] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[20:51:20.118] INFO: ----------------------------------------------------------------------
[20:51:20.118] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[20:51:20.118] INFO: ----------------------------------------------------------------------
[20:51:20.118] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[20:51:20.118] INFO: edge/corner pixel THR is adjusted
[20:51:20.118] INFO: PixTestHighRate::trimHotPixels: step 0...
[20:51:21.078] INFO: Collecting data for 5 seconds...
[20:51:26.094] INFO: Done with hot pixel readout
[20:51:37.775] INFO: PixTest:: pg_setup set to default.
[20:51:37.776] INFO: 320 hot pixels found in step 0
[20:51:38.764] INFO: Collecting data for 5 seconds...
[20:51:43.780] INFO: Done with hot pixel readout
[20:51:55.146] INFO: PixTest:: pg_setup set to default.
[20:51:55.147] INFO: 80 hot pixels found in step 1
[20:51:56.140] INFO: Collecting data for 5 seconds...
[20:52:01.159] INFO: Done with hot pixel readout
[20:52:12.309] INFO: PixTest:: pg_setup set to default.
[20:52:12.310] INFO: 51 hot pixels found in step 2
[20:52:13.299] INFO: Collecting data for 5 seconds...
[20:52:18.318] INFO: Done with hot pixel readout
[20:52:29.664] INFO: PixTest:: pg_setup set to default.
[20:52:29.664] INFO: 31 hot pixels found in step 3
[20:52:30.654] INFO: Collecting data for 5 seconds...
[20:52:35.672] INFO: Done with hot pixel readout
[20:52:46.576] INFO: PixTest:: pg_setup set to default.
[20:52:46.577] INFO: 22 hot pixels found in step 4
[20:52:47.567] INFO: Collecting data for 5 seconds...
[20:52:52.584] INFO: Done with hot pixel readout
[20:53:03.678] INFO: PixTest:: pg_setup set to default.


[20:53:03.679] INFO: 25 hot pixels found in step 5
[20:53:04.669] INFO: Collecting data for 5 seconds...
[20:53:09.687] INFO: Done with hot pixel readout
[20:53:20.816] INFO: PixTest:: pg_setup set to default.


[20:53:20.817] INFO: 14 hot pixels found in step 6
[20:53:21.806] INFO: Collecting data for 5 seconds...
[20:53:26.825] INFO: Done with hot pixel readout
[20:53:38.129] INFO: PixTest:: pg_setup set to default.
[20:53:38.130] INFO: 12 hot pixels found in step 7
[20:53:39.120] INFO: Collecting data for 5 seconds...
[20:53:44.138] INFO: Done with hot pixel readout
[20:53:55.342] INFO: PixTest:: pg_setup set to default.



[20:53:55.343] INFO: 16 hot pixels found in step 8
[20:53:56.333] INFO: Collecting data for 5 seconds...
[20:54:01.351] INFO: Done with hot pixel readout
[20:54:12.173] INFO: PixTest:: pg_setup set to default.

[20:54:12.174] INFO: 9 hot pixels found in step 9
[20:54:13.163] INFO: Collecting data for 5 seconds...
[20:54:18.183] INFO: Done with hot pixel readout
[20:54:29.417] INFO: PixTest:: pg_setup set to default.




[20:54:29.418] INFO: 12 hot pixels found in step 10
[20:54:30.409] INFO: Collecting data for 5 seconds...
[20:54:35.429] INFO: Done with hot pixel readout
[20:54:46.819] INFO: PixTest:: pg_setup set to default.




[20:54:46.820] INFO: 9 hot pixels found in step 11
[20:54:47.809] INFO: Collecting data for 5 seconds...
[20:54:52.828] INFO: Done with hot pixel readout
[20:55:04.444] INFO: PixTest:: pg_setup set to default.


[20:55:04.444] INFO: 10 hot pixels found in step 12
[20:55:05.433] INFO: Collecting data for 5 seconds...
[20:55:10.454] INFO: Done with hot pixel readout
[20:55:22.024] INFO: PixTest:: pg_setup set to default.


[20:55:22.025] INFO: 8 hot pixels found in step 13
[20:55:23.014] INFO: Collecting data for 5 seconds...
[20:55:28.031] INFO: Done with hot pixel readout
[20:55:39.567] INFO: PixTest:: pg_setup set to default.

[20:55:39.568] INFO: 3 hot pixels found in step 14
[20:55:39.602] INFO: 3 hot pixels could not be trimmed and have been masked.
[20:55:39.605] INFO: PixTest::trimHotPixels() done
[20:55:39.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C0.dat
[20:55:39.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C1.dat
[20:55:39.635] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C2.dat
[20:55:39.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C3.dat
[20:55:39.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C4.dat
[20:55:39.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C5.dat
[20:55:39.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C6.dat
[20:55:39.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C7.dat
[20:55:39.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C8.dat
[20:55:39.677] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C9.dat
[20:55:39.682] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C10.dat
[20:55:39.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C11.dat
[20:55:39.694] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C12.dat
[20:55:39.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C13.dat
[20:55:39.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C14.dat
[20:55:39.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C15.dat
[20:55:39.718] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//defaultMaskFile.dat
[20:55:39.729] INFO: enter test to run
[20:58:58.317] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[20:58:58.317] INFO: running: highrate
[20:58:58.322] INFO: ----------------------------------------------------------------------
[20:58:58.322] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[20:58:58.322] INFO: ----------------------------------------------------------------------
[20:58:58.322] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[20:58:58.322] INFO: edge/corner pixel THR is adjusted
[20:58:58.322] INFO: PixTestHighRate::trimHotPixels: step 0...
[20:58:59.280] INFO: Collecting data for 1 seconds...
[20:59:00.283] INFO: Done with hot pixel readout
[20:59:03.965] INFO: PixTest:: pg_setup set to default.
[20:59:03.966] INFO: 0 hot pixels found in step 0
[20:59:03.973] INFO: 0 hot pixels could not be trimmed and have been masked.
[20:59:04.076] INFO: PixTest::trimHotPixels() done
[20:59:04.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C0.dat
[20:59:04.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C1.dat
[20:59:04.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C2.dat
[20:59:04.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C3.dat
[20:59:04.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C4.dat
[20:59:04.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C5.dat
[20:59:04.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C6.dat
[20:59:04.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C7.dat
[20:59:04.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C8.dat
[20:59:04.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C9.dat
[20:59:04.137] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C10.dat
[20:59:04.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C11.dat
[20:59:04.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C12.dat
[20:59:04.155] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C13.dat
[20:59:04.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C14.dat
[20:59:04.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//trimParameters35_C15.dat
[20:59:04.172] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-46_FPIXTest-17C-FNAL-160811-1113_2016-08-11_11h13m_1470932004/000_FPIXTest_p17//defaultMaskFile.dat
[20:59:04.182] INFO: enter test to run
[21:01:37.916] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[21:01:37.916] INFO: running: xray
[21:01:37.917] INFO: ----------------------------------------------------------------------
[21:01:37.917] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[21:01:37.917] INFO: ----------------------------------------------------------------------
[21:01:38.881] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[21:01:50.872] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[21:02:19.935] INFO: Resuming triggers.
[21:02:31.924] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[21:03:01.085] INFO: Resuming triggers.
[21:03:13.068] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[21:03:42.239] INFO: Resuming triggers.
[21:03:54.222] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[21:04:23.960] INFO: Resuming triggers.
[21:04:35.943] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[21:05:05.464] INFO: Resuming triggers.
[21:05:17.452] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[21:05:46.581] INFO: Resuming triggers.
[21:05:58.567] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[21:06:27.502] INFO: Resuming triggers.
[21:06:39.494] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[21:07:09.759] INFO: Resuming triggers.
[21:07:14.208] INFO: data taking finished, elapsed time: 100 seconds.
[21:07:25.572] INFO: PixTest:: pg_setup set to default.
[21:07:25.575] INFO: PixTestXray::doPhRun() done
[21:07:25.710] INFO: enter test to run
[21:08:39.361] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[21:08:39.361] INFO: running: xray
[21:08:39.363] INFO: ----------------------------------------------------------------------
[21:08:39.363] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[21:08:39.363] INFO: ----------------------------------------------------------------------
[21:08:40.327] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[21:08:47.850] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[21:09:17.972] INFO: Resuming triggers.
[21:09:25.499] INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[21:09:55.684] INFO: Resuming triggers.
[21:10:03.212] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[21:10:33.355] INFO: Resuming triggers.
[21:10:40.880] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[21:11:10.002] INFO: Resuming triggers.
[21:11:18.525] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[21:11:48.660] INFO: Resuming triggers.
[21:11:56.183] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[21:12:26.398] INFO: Resuming triggers.
[21:12:33.920] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[21:13:03.004] INFO: Resuming triggers.
[21:13:11.523] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[21:13:41.610] INFO: Resuming triggers.
[21:13:49.125] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[21:14:19.298] INFO: Resuming triggers.
[21:14:26.817] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[21:14:57.027] INFO: Resuming triggers.
[21:15:04.539] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[21:15:34.643] INFO: Resuming triggers.
[21:15:42.157] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[21:16:12.391] INFO: Resuming triggers.
[21:16:19.900] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[21:16:50.732] INFO: Resuming triggers.
[21:16:53.293] INFO: data taking finished, elapsed time: 100 seconds.
[21:17:04.127] INFO: PixTest:: pg_setup set to default.
[21:17:04.130] INFO: PixTestXray::doPhRun() done
[21:17:04.280] INFO: enter test to run
[21:17:35.238] INFO: test: HighRate no parameter change
[21:17:35.238] INFO: running: highrate
[21:17:35.250] INFO: ----------------------------------------------------------------------
[21:17:35.250] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[21:17:35.250] INFO: ----------------------------------------------------------------------
[21:17:35.405] INFO: Expecting 768 events.
[21:17:36.538] INFO: 768 events read in total (418ms).
[21:17:36.538] INFO: Test took 1267ms.
[21:17:37.341] INFO: Expecting 41600 events.
[21:17:40.386] INFO: 41600 events read in total (2518ms).
[21:17:40.387] INFO: Test took 3843ms.
[21:17:40.419] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:17:41.148] INFO: Expecting 41600 events.
[21:17:44.282] INFO: 41600 events read in total (2607ms).
[21:17:44.283] INFO: Test took 3848ms.
[21:17:44.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:17:45.044] INFO: Expecting 41600 events.
[21:17:48.253] INFO: 41600 events read in total (2682ms).
[21:17:48.254] INFO: Test took 3921ms.
[21:17:48.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:17:49.015] INFO: Expecting 41600 events.
[21:17:52.218] INFO: 41600 events read in total (2676ms).
[21:17:52.219] INFO: Test took 3916ms.
[21:17:52.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:17:52.971] INFO: Expecting 41600 events.
[21:17:56.245] INFO: 41600 events read in total (2747ms).
[21:17:56.246] INFO: Test took 3977ms.
[21:17:56.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:17:56.004] INFO: Expecting 41600 events.
[21:18:00.253] INFO: 41600 events read in total (2722ms).
[21:18:00.254] INFO: Test took 3960ms.
[21:18:00.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:01.014] INFO: Expecting 41600 events.
[21:18:04.259] INFO: 41600 events read in total (2718ms).
[21:18:04.260] INFO: Test took 3956ms.
[21:18:04.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:05.019] INFO: Expecting 41600 events.
[21:18:08.254] INFO: 41600 events read in total (2709ms).
[21:18:08.255] INFO: Test took 3945ms.
[21:18:08.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:09.008] INFO: Expecting 41600 events.
[21:18:12.169] INFO: 41600 events read in total (2634ms).
[21:18:12.169] INFO: Test took 3864ms.
[21:18:12.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:12.923] INFO: Expecting 41600 events.
[21:18:16.067] INFO: 41600 events read in total (2617ms).
[21:18:16.068] INFO: Test took 3849ms.
[21:18:16.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:16.823] INFO: Expecting 41600 events.
[21:18:19.000] INFO: 41600 events read in total (2650ms).
[21:18:19.001] INFO: Test took 3884ms.
[21:18:20.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:20.763] INFO: Expecting 41600 events.
[21:18:23.988] INFO: 41600 events read in total (2698ms).
[21:18:23.989] INFO: Test took 3939ms.
[21:18:24.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:24.747] INFO: Expecting 41600 events.
[21:18:28.094] INFO: 41600 events read in total (2820ms).
[21:18:28.095] INFO: Test took 4055ms.
[21:18:28.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:28.855] INFO: Expecting 41600 events.
[21:18:32.049] INFO: 41600 events read in total (2667ms).
[21:18:32.136] INFO: Test took 3992ms.
[21:18:32.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:32.816] INFO: Expecting 41600 events.
[21:18:36.059] INFO: 41600 events read in total (2716ms).
[21:18:36.060] INFO: Test took 3857ms.
[21:18:36.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:36.819] INFO: Expecting 41600 events.
[21:18:40.068] INFO: 41600 events read in total (2723ms).
[21:18:40.069] INFO: Test took 3959ms.
[21:18:40.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:40.827] INFO: Expecting 41600 events.
[21:18:44.110] INFO: 41600 events read in total (2756ms).
[21:18:44.111] INFO: Test took 3993ms.
[21:18:44.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:44.872] INFO: Expecting 41600 events.
[21:18:48.148] INFO: 41600 events read in total (2749ms).
[21:18:48.149] INFO: Test took 3988ms.
[21:18:48.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:48.904] INFO: Expecting 41600 events.
[21:18:52.046] INFO: 41600 events read in total (2615ms).
[21:18:52.047] INFO: Test took 3848ms.
[21:18:52.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:52.805] INFO: Expecting 41600 events.
[21:18:55.965] INFO: 41600 events read in total (2633ms).
[21:18:55.966] INFO: Test took 3870ms.
[21:18:55.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:18:56.355] INFO: enter test to run
[21:19:01.509] INFO: test: HighRate no parameter change
[21:19:01.509] INFO: running: highrate
[21:19:01.510] INFO: ----------------------------------------------------------------------
[21:19:01.510] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[21:19:01.510] INFO: ----------------------------------------------------------------------
[21:19:02.127] INFO: Expecting 208000 events.
[21:19:14.086] INFO: 208000 events read in total (11432ms).
[21:19:14.090] INFO: Test took 12574ms.
[21:19:14.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:19:14.546] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 31 190 73 51 3 0 0 0 0
[21:19:14.546] INFO: number of red-efficiency pixels: 81 52 82 94 123 122 135 113 855 208 147 103 87 59 15 18
[21:19:14.546] INFO: number of X-ray hits detected: 62156 38798 55595 88195 95944 98961 97847 72183 132479 89308 83002 74022 72265 42818 16942 20929
[21:19:14.546] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[21:19:14.547] INFO: number of Vcal hits detected: 207916 207948 207916 207903 207876 207877 207859 206364 197775 204179 205352 207730 207913 207940 207985 207982
[21:19:14.547] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.6 99.9 100.0 99.9 100.0 100.0 100.0 100.0
[21:19:14.547] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.2 95.1 98.2 98.7 99.9 100.0 100.0 100.0 100.0
[21:19:14.547] INFO: X-ray hit rate [MHz/cm2]: 18.2 11.4 16.3 25.9 28.1 29.0 28.7 21.2 38.8 26.2 24.3 21.7 21.2 12.6 5.0 6.1
[21:19:14.547] INFO: PixTestHighRate::doXPixelAlive() done
[21:19:14.594] INFO: PixTest:: pg_setup set to default.
[21:19:14.608] INFO: enter test to run
[21:19:35.605] INFO: test: HighRate no parameter change
[21:19:35.605] INFO: running: highrate
[21:19:35.606] INFO: ----------------------------------------------------------------------
[21:19:35.606] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[21:19:35.606] INFO: ----------------------------------------------------------------------
[21:19:36.228] INFO: Expecting 208000 events.
[21:19:49.577] INFO: 208000 events read in total (12822ms).
[21:19:49.581] INFO: Test took 13966ms.
[21:19:49.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:19:50.130] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 31 190 73 51 3 0 0 0 0
[21:19:50.130] INFO: number of red-efficiency pixels: 223 76 193 326 368 326 363 213 774 341 311 253 226 118 40 51
[21:19:50.130] INFO: number of X-ray hits detected: 123629 76781 110391 173651 191236 195875 193164 142397 196273 169470 164508 146635 144041 84904 33914 41036
[21:19:50.130] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[21:19:50.130] INFO: number of Vcal hits detected: 207768 207923 207795 207653 207606 207652 207609 206257 197850 204020 205185 207563 207761 207876 207960 207944
[21:19:50.130] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.7 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[21:19:50.130] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.2 95.1 98.1 98.6 99.8 99.9 99.9 100.0 100.0
[21:19:50.130] INFO: X-ray hit rate [MHz/cm2]: 36.2 22.5 32.4 50.9 56.1 57.4 56.6 41.7 57.5 49.7 48.2 43.0 42.2 24.9 9.9 12.0
[21:19:50.130] INFO: PixTestHighRate::doXPixelAlive() done
[21:19:50.176] INFO: PixTest:: pg_setup set to default.
[21:19:50.190] INFO: enter test to run
[21:20:01.564] INFO: test: HighRate no parameter change
[21:20:01.564] INFO: running: highrate
[21:20:01.566] INFO: ----------------------------------------------------------------------
[21:20:01.566] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[21:20:01.566] INFO: ----------------------------------------------------------------------
[21:20:02.185] INFO: Expecting 208000 events.
[21:20:17.045] INFO: 208000 events read in total (14334ms).
[21:20:17.051] INFO: Test took 15476ms.
[21:20:17.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:20:17.757] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 31 190 73 51 3 0 0 0 0
[21:20:17.757] INFO: number of red-efficiency pixels: 469 199 428 687 842 687 868 472 884 631 600 536 494 299 62 71
[21:20:17.757] INFO: number of X-ray hits detected: 186814 115911 166642 260551 288209 294446 289756 211947 256474 249965 247173 220688 216296 128033 51148 62949
[21:20:17.758] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[21:20:17.758] INFO: number of Vcal hits detected: 207434 207782 207490 207216 207010 207208 206956 205958 197712 203671 204823 207217 207467 207679 207936 207928
[21:20:17.758] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.6 99.8 99.6 99.7 99.7 99.7 99.8 99.9 100.0 100.0
[21:20:17.758] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.6 99.5 99.6 99.5 99.0 95.1 97.9 98.5 99.6 99.7 99.8 100.0 100.0
[21:20:17.758] INFO: X-ray hit rate [MHz/cm2]: 54.8 34.0 48.8 76.4 84.5 86.3 84.9 62.1 75.2 73.3 72.4 64.7 63.4 37.5 15.0 18.5
[21:20:17.758] INFO: PixTestHighRate::doXPixelAlive() done
[21:20:17.805] INFO: PixTest:: pg_setup set to default.
[21:20:17.817] INFO: enter test to run
[21:20:21.100] INFO: test: exit no parameter change
[21:20:21.416] QUIET: Connection to board 33 closed.
[21:20:21.418] INFO: pXar: this is the end, my friend