[18:46:03.066] INFO: *** Welcome to pxar ***
[18:46:03.066] INFO: *** Today: 2016/06/06
[18:46:03.086] INFO: *** Version: v1.9.0-814-g7497
[18:46:03.086] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//dacParameters35_C15.dat
[18:46:03.122] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:46:03.122] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//defaultMaskFile.dat
[18:46:03.124] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C15.dat
[18:46:03.231] INFO: clk: 4
[18:46:03.231] INFO: ctr: 4
[18:46:03.231] INFO: sda: 19
[18:46:03.231] INFO: tin: 9
[18:46:03.231] INFO: level: 15
[18:46:03.231] INFO: triggerdelay: 0
[18:46:03.231] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:46:03.231] INFO: Log level: INFO
[18:46:03.249] QUIET: Connection to board DTB_WREK4U opened.
[18:46:03.253] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[18:46:03.256] INFO: RPC call hashes of host and DTB match: 398089610
[18:46:04.785] INFO: DUT info:
[18:46:04.785] INFO: The DUT currently contains the following objects:
[18:46:04.785] INFO: 2 TBM Cores tbm08c (2 ON)
[18:46:04.785] INFO: TBM Core alpha (0): 7 registers set
[18:46:04.785] INFO: TBM Core beta (1): 7 registers set
[18:46:04.785] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:46:04.785] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.785] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:04.786] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:46:05.189] INFO: enter 'restricted' command line mode
[18:46:05.189] INFO: enter test to run
[18:46:10.405] INFO: test: PixelAlive no parameter change
[18:46:10.405] INFO: running: pixelalive
[18:46:10.414] INFO: ----------------------------------------------------------------------
[18:46:10.414] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:46:10.414] INFO: ----------------------------------------------------------------------
[18:46:10.737] INFO: Expecting 41600 events.
[18:46:15.058] INFO: 41600 events read in total (3603ms).
[18:46:15.227] INFO: Test took 4809ms.
[18:46:15.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:15.504] INFO: PixTestAlive::aliveTest() done
[18:46:15.504] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[18:46:15.534] INFO: enter test to run
[18:46:29.173] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:46:29.173] INFO: running: highrate
[18:46:29.173] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:46:29.417] INFO: ----------------------------------------------------------------------
[18:46:29.417] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:46:29.417] INFO: ----------------------------------------------------------------------
[18:46:29.417] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:46:29.418] INFO: edge/corner pixel THR is adjusted
[18:46:29.418] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:46:30.377] INFO: Collecting data for 5 seconds...
[18:46:35.392] INFO: Done with hot pixel readout
[18:46:48.754] INFO: PixTest:: pg_setup set to default.


















[18:46:48.787] INFO: 591 hot pixels found in step 0
[18:46:49.787] INFO: Collecting data for 5 seconds...
[18:46:54.804] INFO: Done with hot pixel readout
[18:47:08.154] INFO: PixTest:: pg_setup set to default.






























[18:47:08.156] INFO: 581 hot pixels found in step 1
[18:47:09.155] INFO: Collecting data for 5 seconds...
[18:47:14.171] INFO: Done with hot pixel readout
[18:47:27.547] INFO: PixTest:: pg_setup set to default.













































[18:47:27.549] INFO: 532 hot pixels found in step 2
[18:47:28.552] INFO: Collecting data for 5 seconds...
[18:47:33.568] INFO: Done with hot pixel readout
[18:47:46.944] INFO: PixTest:: pg_setup set to default.




























































[18:47:46.946] INFO: 466 hot pixels found in step 3
[18:47:47.947] INFO: Collecting data for 5 seconds...
[18:47:52.963] INFO: Done with hot pixel readout
[18:48:06.329] INFO: PixTest:: pg_setup set to default.







































































[18:48:06.332] INFO: 442 hot pixels found in step 4
[18:48:07.334] INFO: Collecting data for 5 seconds...
[18:48:12.350] INFO: Done with hot pixel readout
[18:48:25.783] INFO: PixTest:: pg_setup set to default.























































































[18:48:25.786] INFO: 439 hot pixels found in step 5
[18:48:26.788] INFO: Collecting data for 5 seconds...
[18:48:31.807] INFO: Done with hot pixel readout
[18:48:45.245] INFO: PixTest:: pg_setup set to default.

























































































[18:48:45.248] INFO: 403 hot pixels found in step 6
[18:48:46.249] INFO: Collecting data for 5 seconds...
[18:48:51.267] INFO: Done with hot pixel readout
[18:49:04.841] INFO: PixTest:: pg_setup set to default.





































































































[18:49:04.844] INFO: 375 hot pixels found in step 7
[18:49:05.846] INFO: Collecting data for 5 seconds...
[18:49:10.864] INFO: Done with hot pixel readout
[18:49:23.778] INFO: PixTest:: pg_setup set to default.


















































































































[18:49:23.781] INFO: 354 hot pixels found in step 8
[18:49:24.784] INFO: Collecting data for 5 seconds...
[18:49:29.802] INFO: Done with hot pixel readout
[18:49:42.983] INFO: PixTest:: pg_setup set to default.































































































































[18:49:42.987] INFO: 349 hot pixels found in step 9
[18:49:43.989] INFO: Collecting data for 5 seconds...
[18:49:49.007] INFO: Done with hot pixel readout
[18:50:02.201] INFO: PixTest:: pg_setup set to default.



































































































































[18:50:02.213] INFO: 332 hot pixels found in step 10
[18:50:03.219] INFO: Collecting data for 5 seconds...
[18:50:08.239] INFO: Done with hot pixel readout
[18:50:21.838] INFO: PixTest:: pg_setup set to default.











































































































[18:50:21.842] INFO: 288 hot pixels found in step 11
[18:50:22.844] INFO: Collecting data for 5 seconds...
[18:50:27.864] INFO: Done with hot pixel readout
[18:50:41.620] INFO: PixTest:: pg_setup set to default.

















































































































































[18:50:41.632] INFO: 295 hot pixels found in step 12
[18:50:42.636] INFO: Collecting data for 5 seconds...
[18:50:47.654] INFO: Done with hot pixel readout
[18:51:01.301] INFO: PixTest:: pg_setup set to default.




























































































































































[18:51:01.316] INFO: 315 hot pixels found in step 13
[18:51:02.322] INFO: Collecting data for 5 seconds...
[18:51:07.342] INFO: Done with hot pixel readout
[18:51:21.011] INFO: PixTest:: pg_setup set to default.



























































































































































[18:51:21.024] INFO: 296 hot pixels found in step 14
[18:51:21.073] INFO: 296 hot pixels could not be trimmed and have been masked.
[18:51:21.077] INFO: PixTest::trimHotPixels() done
[18:51:21.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C0.dat
[18:51:21.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C1.dat
[18:51:21.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C2.dat
[18:51:21.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C3.dat
[18:51:21.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C4.dat
[18:51:21.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C5.dat
[18:51:21.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C6.dat
[18:51:21.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C7.dat
[18:51:21.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C8.dat
[18:51:21.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C9.dat
[18:51:21.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C10.dat
[18:51:21.137] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C11.dat
[18:51:21.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C12.dat
[18:51:21.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C13.dat
[18:51:21.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C14.dat
[18:51:21.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C15.dat
[18:51:21.163] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//defaultMaskFile.dat
[18:51:21.175] INFO: enter test to run
[18:51:52.130] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:51:52.130] INFO: running: highrate
[18:51:52.136] INFO: ----------------------------------------------------------------------
[18:51:52.136] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:51:52.136] INFO: ----------------------------------------------------------------------
[18:51:52.136] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:51:52.136] INFO: edge/corner pixel THR is adjusted
[18:51:52.136] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:51:53.093] INFO: Collecting data for 1 seconds...
[18:51:54.097] INFO: Done with hot pixel readout
[18:51:59.149] INFO: PixTest:: pg_setup set to default.
[18:51:59.150] INFO: 0 hot pixels found in step 0
[18:51:59.156] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:51:59.199] INFO: PixTest::trimHotPixels() done
[18:51:59.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C0.dat
[18:51:59.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C1.dat
[18:51:59.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C2.dat
[18:51:59.219] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C3.dat
[18:51:59.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C4.dat
[18:51:59.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C5.dat
[18:51:59.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C6.dat
[18:51:59.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C7.dat
[18:51:59.246] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C8.dat
[18:51:59.251] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C9.dat
[18:51:59.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C10.dat
[18:51:59.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C11.dat
[18:51:59.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C12.dat
[18:51:59.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C13.dat
[18:51:59.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C14.dat
[18:51:59.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//trimParameters35_C15.dat
[18:51:59.289] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-T-NK_FPIXTest-17C-FNAL-160601-0922_2016-06-01_09h23m_1464790980/000_FPIXTest_p17//defaultMaskFile.dat
[18:51:59.298] INFO: enter test to run
[18:53:21.162] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:53:21.162] INFO: running: xray
[18:53:21.163] INFO: ----------------------------------------------------------------------
[18:53:21.163] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:53:21.163] INFO: ----------------------------------------------------------------------
[18:53:22.127] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:53:32.005] INFO: run duration 9 seconds, buffer almost full (81%), pausing triggers.
[18:54:01.575] INFO: Resuming triggers.
[18:54:11.453] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[18:54:41.107] INFO: Resuming triggers.
[18:54:52.432] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[18:55:21.746] INFO: Resuming triggers.
[18:55:33.334] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[18:56:02.624] INFO: Resuming triggers.
[18:56:14.279] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[18:56:43.246] INFO: Resuming triggers.
[18:56:54.799] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[18:57:23.747] INFO: Resuming triggers.
[18:57:35.398] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[18:58:04.631] INFO: Resuming triggers.
[18:58:16.222] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[18:58:45.476] INFO: Resuming triggers.
[18:58:56.680] INFO: data taking finished, elapsed time: 100 seconds.
[18:59:24.496] INFO: PixTest:: pg_setup set to default.
[18:59:24.499] INFO: PixTestXray::doPhRun() done
[18:59:24.635] INFO: enter test to run
[19:00:28.895] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[19:00:28.895] INFO: running: xray
[19:00:28.896] INFO: ----------------------------------------------------------------------
[19:00:28.896] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:00:28.896] INFO: ----------------------------------------------------------------------
[19:00:29.872] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:00:35.077] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[19:01:05.705] INFO: Resuming triggers.
[19:01:10.907] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[19:01:41.680] INFO: Resuming triggers.
[19:01:46.886] INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[19:02:18.269] INFO: Resuming triggers.
[19:02:23.470] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[19:02:55.025] INFO: Resuming triggers.
[19:03:00.226] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[19:03:30.624] INFO: Resuming triggers.
[19:03:35.831] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[19:04:05.936] INFO: Resuming triggers.
[19:04:11.140] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[19:04:41.237] INFO: Resuming triggers.
[19:04:46.442] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[19:05:16.534] INFO: Resuming triggers.
[19:05:21.740] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[19:05:51.794] INFO: Resuming triggers.
[19:05:56.000] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[19:06:27.013] INFO: Resuming triggers.
[19:06:32.221] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[19:07:02.275] INFO: Resuming triggers.
[19:07:07.480] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[19:07:37.525] INFO: Resuming triggers.
[19:07:42.730] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[19:08:12.746] INFO: Resuming triggers.
[19:08:17.949] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[19:08:48.002] INFO: Resuming triggers.
[19:08:53.205] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[19:09:23.212] INFO: Resuming triggers.
[19:09:28.419] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[19:09:58.466] INFO: Resuming triggers.
[19:10:03.668] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[19:10:33.612] INFO: Resuming triggers.
[19:10:38.818] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[19:11:08.894] INFO: Resuming triggers.
[19:11:14.098] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[19:11:45.173] INFO: Resuming triggers.
[19:11:46.630] INFO: data taking finished, elapsed time: 100 seconds.
[19:11:55.553] INFO: PixTest:: pg_setup set to default.
[19:11:55.556] INFO: PixTestXray::doPhRun() done
[19:11:55.712] INFO: enter test to run
[19:13:35.393] INFO: test: HighRate no parameter change
[19:13:35.393] INFO: running: highrate
[19:13:35.394] INFO: ----------------------------------------------------------------------
[19:13:35.394] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[19:13:35.394] INFO: ----------------------------------------------------------------------
[19:13:35.535] INFO: Expecting 768 events.
[19:13:36.672] INFO: 768 events read in total (422ms).
[19:13:36.672] INFO: Test took 1272ms.
[19:13:37.474] INFO: Expecting 41600 events.
[19:13:40.792] INFO: 41600 events read in total (2791ms).
[19:13:40.794] INFO: Test took 4115ms.
[19:13:40.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:41.523] INFO: Expecting 41600 events.
[19:13:44.864] INFO: 41600 events read in total (2814ms).
[19:13:44.865] INFO: Test took 4003ms.
[19:13:44.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:45.612] INFO: Expecting 41600 events.
[19:13:49.061] INFO: 41600 events read in total (2922ms).
[19:13:49.062] INFO: Test took 4126ms.
[19:13:49.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:49.803] INFO: Expecting 41600 events.
[19:13:53.156] INFO: 41600 events read in total (2826ms).
[19:13:53.157] INFO: Test took 4025ms.
[19:13:53.206] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:53.902] INFO: Expecting 41600 events.
[19:13:57.313] INFO: 41600 events read in total (2884ms).
[19:13:57.315] INFO: Test took 4087ms.
[19:13:57.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:58.053] INFO: Expecting 41600 events.
[19:14:01.507] INFO: 41600 events read in total (2927ms).
[19:14:01.508] INFO: Test took 4123ms.
[19:14:01.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:02.249] INFO: Expecting 41600 events.
[19:14:05.636] INFO: 41600 events read in total (2860ms).
[19:14:05.637] INFO: Test took 4059ms.
[19:14:05.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:06.383] INFO: Expecting 41600 events.
[19:14:09.794] INFO: 41600 events read in total (2884ms).
[19:14:09.795] INFO: Test took 4089ms.
[19:14:09.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:10.531] INFO: Expecting 41600 events.
[19:14:13.927] INFO: 41600 events read in total (2869ms).
[19:14:13.929] INFO: Test took 4062ms.
[19:14:13.976] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:14.673] INFO: Expecting 41600 events.
[19:14:18.199] INFO: 41600 events read in total (3000ms).
[19:14:18.200] INFO: Test took 4202ms.
[19:14:18.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:18.944] INFO: Expecting 41600 events.
[19:14:22.540] INFO: 41600 events read in total (3069ms).
[19:14:22.542] INFO: Test took 4272ms.
[19:14:22.589] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:23.283] INFO: Expecting 41600 events.
[19:14:26.742] INFO: 41600 events read in total (2932ms).
[19:14:26.743] INFO: Test took 4132ms.
[19:14:26.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:27.485] INFO: Expecting 41600 events.
[19:14:30.887] INFO: 41600 events read in total (2875ms).
[19:14:30.888] INFO: Test took 4073ms.
[19:14:30.936] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:31.634] INFO: Expecting 41600 events.
[19:14:35.035] INFO: 41600 events read in total (2874ms).
[19:14:35.037] INFO: Test took 4078ms.
[19:14:35.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:35.782] INFO: Expecting 41600 events.
[19:14:39.453] INFO: 41600 events read in total (3144ms).
[19:14:39.454] INFO: Test took 4348ms.
[19:14:39.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:40.201] INFO: Expecting 41600 events.
[19:14:43.616] INFO: 41600 events read in total (2889ms).
[19:14:43.618] INFO: Test took 4094ms.
[19:14:43.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:44.362] INFO: Expecting 41600 events.
[19:14:47.778] INFO: 41600 events read in total (2889ms).
[19:14:47.779] INFO: Test took 4091ms.
[19:14:47.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:48.521] INFO: Expecting 41600 events.
[19:14:52.077] INFO: 41600 events read in total (3030ms).
[19:14:52.078] INFO: Test took 4227ms.
[19:14:52.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:52.824] INFO: Expecting 41600 events.
[19:14:56.181] INFO: 41600 events read in total (2831ms).
[19:14:56.182] INFO: Test took 4032ms.
[19:14:56.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:14:56.932] INFO: Expecting 41600 events.
[19:15:00.136] INFO: 41600 events read in total (2677ms).
[19:15:00.137] INFO: Test took 3885ms.
[19:15:00.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:15:00.524] INFO: enter test to run
[19:15:10.856] INFO: test: HighRate no parameter change
[19:15:10.856] INFO: running: highrate
[19:15:10.857] INFO: ----------------------------------------------------------------------
[19:15:10.857] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:15:10.857] INFO: ----------------------------------------------------------------------
[19:15:11.472] INFO: Expecting 208000 events.
[19:15:24.118] INFO: 208000 events read in total (12119ms).
[19:15:24.122] INFO: Test took 13259ms.
[19:15:24.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:15:24.612] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[19:15:24.612] INFO: number of red-efficiency pixels: 94 82 134 238 285 209 237 125 133 239 245 234 179 87 36 25
[19:15:24.612] INFO: number of X-ray hits detected: 86971 60109 95952 155418 167260 165248 164676 109850 109096 156735 156498 137117 136866 79494 31977 32951
[19:15:24.612] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:15:24.612] INFO: number of Vcal hits detected: 207905 207917 207835 207750 207657 207785 207756 207872 207860 207752 207744 207759 207813 207912 207964 207975
[19:15:24.612] 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
[19:15:24.612] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[19:15:24.612] INFO: X-ray hit rate [MHz/cm2]: 25.5 17.6 28.1 45.6 49.0 48.4 48.3 32.2 32.0 45.9 45.9 40.2 40.1 23.3 9.4 9.7
[19:15:24.612] INFO: PixTestHighRate::doXPixelAlive() done
[19:15:24.663] INFO: PixTest:: pg_setup set to default.
[19:15:24.675] INFO: enter test to run
[19:16:15.848] INFO: test: HighRate no parameter change
[19:16:15.848] INFO: running: highrate
[19:16:15.849] INFO: ----------------------------------------------------------------------
[19:16:15.849] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:16:15.849] INFO: ----------------------------------------------------------------------
[19:16:16.466] INFO: Expecting 208000 events.
[19:16:31.828] INFO: 208000 events read in total (14835ms).
[19:16:31.835] INFO: Test took 15977ms.
[19:16:32.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:16:32.619] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[19:16:32.619] INFO: number of red-efficiency pixels: 351 179 457 1086 1196 879 879 523 387 1119 1040 735 609 301 84 71
[19:16:32.619] INFO: number of X-ray hits detected: 179170 123667 198803 321036 344669 340067 340157 227938 225005 324707 322677 283455 282801 164010 66437 68449
[19:16:32.619] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:16:32.619] INFO: number of Vcal hits detected: 207607 207815 207417 206681 206453 206960 206982 207406 207571 206627 206709 207128 207336 207670 207913 207927
[19:16:32.619] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.3 99.5 99.6 99.7 99.8 99.4 99.4 99.6 99.7 99.9 100.0 100.0
[19:16:32.619] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.4 99.3 99.5 99.5 99.7 99.8 99.3 99.4 99.6 99.7 99.8 100.0 100.0
[19:16:32.619] INFO: X-ray hit rate [MHz/cm2]: 52.5 36.2 58.3 94.1 101.0 99.7 99.7 66.8 66.0 95.2 94.6 83.1 82.9 48.1 19.5 20.1
[19:16:32.619] INFO: PixTestHighRate::doXPixelAlive() done
[19:16:32.671] INFO: PixTest:: pg_setup set to default.
[19:16:32.688] INFO: enter test to run
[19:16:51.015] INFO: test: HighRate no parameter change
[19:16:51.015] INFO: running: highrate
[19:16:51.016] INFO: ----------------------------------------------------------------------
[19:16:51.016] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:16:51.017] INFO: ----------------------------------------------------------------------
[19:16:51.635] INFO: Expecting 208000 events.
[19:17:10.140] INFO: 208000 events read in total (17978ms).
[19:17:10.150] INFO: Test took 19124ms.
[19:17:10.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:11.235] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[19:17:11.235] INFO: number of red-efficiency pixels: 695 366 1007 2359 2539 2001 1973 1094 919 2317 2375 1686 1402 748 139 133
[19:17:11.235] INFO: number of X-ray hits detected: 269361 185745 297256 479447 514824 511209 510064 341292 338416 486550 482714 423248 422107 246165 99942 102483
[19:17:11.235] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:17:11.235] INFO: number of Vcal hits detected: 207101 207577 206380 203992 203307 204861 204925 206388 206785 203981 203885 205372 206084 207037 207847 207864
[19:17:11.235] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.3 98.3 98.0 98.6 98.7 99.3 99.5 98.3 98.2 98.9 99.2 99.6 99.9 99.9
[19:17:11.235] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.2 98.1 97.7 98.5 98.5 99.2 99.4 98.1 98.0 98.7 99.1 99.5 99.9 99.9
[19:17:11.235] INFO: X-ray hit rate [MHz/cm2]: 79.0 54.4 87.1 140.5 150.9 149.8 149.5 100.0 99.2 142.6 141.5 124.1 123.7 72.2 29.3 30.0
[19:17:11.235] INFO: PixTestHighRate::doXPixelAlive() done
[19:17:11.280] INFO: PixTest:: pg_setup set to default.
[19:17:11.295] INFO: enter test to run
[19:17:16.375] INFO: test: exit no parameter change
[19:17:16.673] QUIET: Connection to board 32 closed.
[19:17:16.674] INFO: pXar: this is the end, my friend