[13:29:53.688] INFO: *** Welcome to pxar ***
[13:29:53.688] INFO: *** Today: 2016/05/03
[13:29:54.033] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:29:54.033] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//dacParameters35_C15.dat
[13:29:54.088] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:29:54.088] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//defaultMaskFile.dat
[13:29:54.088] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C15.dat
[13:29:54.193] INFO: clk: 4
[13:29:54.193] INFO: ctr: 4
[13:29:54.194] INFO: sda: 19
[13:29:54.194] INFO: tin: 9
[13:29:54.194] INFO: level: 15
[13:29:54.194] INFO: triggerdelay: 0
[13:29:54.194] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:29:54.194] INFO: Log level: INFO
[13:29:54.212] QUIET: Connection to board DTB_WREK4U opened.
[13:29:54.215] 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:
------------------------------------------------------
[13:29:54.218] INFO: RPC call hashes of host and DTB match: 398089610
[13:29:55.761] INFO: DUT info:
[13:29:55.761] INFO: The DUT currently contains the following objects:
[13:29:55.761] INFO: 2 TBM Cores tbm08c (2 ON)
[13:29:55.761] INFO: TBM Core alpha (0): 7 registers set
[13:29:55.761] INFO: TBM Core beta (1): 7 registers set
[13:29:55.761] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:29:55.761] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.761] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.761] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.761] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.761] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.761] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.761] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:55.762] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:29:56.230] INFO: enter 'restricted' command line mode
[13:29:56.230] INFO: enter test to run
[13:30:15.662] INFO: test: PixelAlive no parameter change
[13:30:15.662] INFO: running: pixelalive
[13:30:15.689] INFO: ----------------------------------------------------------------------
[13:30:15.689] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:30:15.689] INFO: ----------------------------------------------------------------------
[13:30:16.008] INFO: Expecting 41600 events.
[13:30:20.343] INFO: 41600 events read in total (3617ms).
[13:30:20.507] INFO: Test took 4814ms.
[13:30:20.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:20.781] INFO: PixTestAlive::aliveTest() done
[13:30:20.781] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:30:20.812] INFO: enter test to run
[13:30:57.582] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:30:57.582] INFO: running: highrate
[13:30:57.582] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:30:57.930] INFO: ----------------------------------------------------------------------
[13:30:57.930] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:30:57.930] INFO: ----------------------------------------------------------------------
[13:30:57.930] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:30:57.930] INFO: edge/corner pixel THR is adjusted
[13:30:57.930] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:30:58.891] INFO: Collecting data for 5 seconds...
[13:31:03.907] INFO: Done with hot pixel readout
[13:31:15.709] INFO: PixTest:: pg_setup set to default.
[13:31:15.710] INFO: 3 hot pixels found in step 0
[13:31:16.702] INFO: Collecting data for 5 seconds...
[13:31:21.719] INFO: Done with hot pixel readout
[13:31:33.447] INFO: PixTest:: pg_setup set to default.
[13:31:33.447] INFO: 4 hot pixels found in step 1
[13:31:34.443] INFO: Collecting data for 5 seconds...
[13:31:39.459] INFO: Done with hot pixel readout
[13:31:51.340] INFO: PixTest:: pg_setup set to default.
[13:31:51.341] INFO: 4 hot pixels found in step 2
[13:31:52.336] INFO: Collecting data for 5 seconds...
[13:31:57.353] INFO: Done with hot pixel readout
[13:32:09.242] INFO: PixTest:: pg_setup set to default.
[13:32:09.243] INFO: 3 hot pixels found in step 3
[13:32:10.236] INFO: Collecting data for 5 seconds...
[13:32:15.252] INFO: Done with hot pixel readout
[13:32:27.101] INFO: PixTest:: pg_setup set to default.
[13:32:27.102] INFO: 3 hot pixels found in step 4
[13:32:28.095] INFO: Collecting data for 5 seconds...
[13:32:33.111] INFO: Done with hot pixel readout
[13:32:45.014] INFO: PixTest:: pg_setup set to default.
[13:32:45.015] INFO: 2 hot pixels found in step 5
[13:32:46.009] INFO: Collecting data for 5 seconds...
[13:32:51.025] INFO: Done with hot pixel readout
[13:33:02.948] INFO: PixTest:: pg_setup set to default.
[13:33:02.949] INFO: 1 hot pixels found in step 6
[13:33:03.942] INFO: Collecting data for 5 seconds...
[13:33:08.959] INFO: Done with hot pixel readout
[13:33:20.859] INFO: PixTest:: pg_setup set to default.
[13:33:20.860] INFO: 2 hot pixels found in step 7
[13:33:21.854] INFO: Collecting data for 5 seconds...
[13:33:26.870] INFO: Done with hot pixel readout
[13:33:38.738] INFO: PixTest:: pg_setup set to default.
[13:33:38.738] INFO: 1 hot pixels found in step 8
[13:33:39.731] INFO: Collecting data for 5 seconds...
[13:33:44.747] INFO: Done with hot pixel readout
[13:33:56.604] INFO: PixTest:: pg_setup set to default.
[13:33:56.605] INFO: 1 hot pixels found in step 9
[13:33:57.599] INFO: Collecting data for 5 seconds...
[13:34:02.616] INFO: Done with hot pixel readout
[13:34:14.523] INFO: PixTest:: pg_setup set to default.
[13:34:14.524] INFO: 2 hot pixels found in step 10
[13:34:15.518] INFO: Collecting data for 5 seconds...
[13:34:20.535] INFO: Done with hot pixel readout
[13:34:32.414] INFO: PixTest:: pg_setup set to default.
[13:34:32.415] INFO: 4 hot pixels found in step 11
[13:34:33.408] INFO: Collecting data for 5 seconds...
[13:34:38.425] INFO: Done with hot pixel readout
[13:34:47.371] INFO: PixTest:: pg_setup set to default.
[13:34:47.372] INFO: 4 hot pixels found in step 12
[13:34:48.365] INFO: Collecting data for 5 seconds...
[13:34:53.374] INFO: Done with hot pixel readout
[13:35:03.930] INFO: PixTest:: pg_setup set to default.
[13:35:03.931] INFO: 1 hot pixels found in step 13
[13:35:04.925] INFO: Collecting data for 5 seconds...
[13:35:09.942] INFO: Done with hot pixel readout
[13:35:21.818] INFO: PixTest:: pg_setup set to default.
[13:35:21.819] INFO: 1 hot pixels found in step 14
[13:35:21.856] INFO: 1 hot pixels could not be trimmed and have been masked.
[13:35:21.860] INFO: PixTest::trimHotPixels() done
[13:35:21.860] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C0.dat
[13:35:21.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C1.dat
[13:35:21.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C2.dat
[13:35:21.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C3.dat
[13:35:21.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C4.dat
[13:35:21.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C5.dat
[13:35:21.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C6.dat
[13:35:21.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C7.dat
[13:35:21.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C8.dat
[13:35:21.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C9.dat
[13:35:21.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C10.dat
[13:35:21.922] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C11.dat
[13:35:21.927] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C12.dat
[13:35:21.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C13.dat
[13:35:21.938] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C14.dat
[13:35:21.944] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C15.dat
[13:35:21.949] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//defaultMaskFile.dat
[13:35:21.959] INFO: enter test to run
[13:36:00.971] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:36:00.971] INFO: running: highrate
[13:36:00.975] INFO: ----------------------------------------------------------------------
[13:36:00.975] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:36:00.975] INFO: ----------------------------------------------------------------------
[13:36:00.975] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:36:00.975] INFO: edge/corner pixel THR is adjusted
[13:36:00.975] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:36:01.931] INFO: Collecting data for 1 seconds...
[13:36:02.933] INFO: Done with hot pixel readout
[13:36:06.025] INFO: PixTest:: pg_setup set to default.
[13:36:06.026] INFO: 0 hot pixels found in step 0
[13:36:06.032] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:36:06.123] INFO: PixTest::trimHotPixels() done
[13:36:06.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C0.dat
[13:36:06.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C1.dat
[13:36:06.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C2.dat
[13:36:06.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C3.dat
[13:36:06.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C4.dat
[13:36:06.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C5.dat
[13:36:06.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C6.dat
[13:36:06.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C7.dat
[13:36:06.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C8.dat
[13:36:06.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C9.dat
[13:36:06.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C10.dat
[13:36:06.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C11.dat
[13:36:06.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C12.dat
[13:36:06.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C13.dat
[13:36:06.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C14.dat
[13:36:06.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C15.dat
[13:36:06.211] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-03_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//defaultMaskFile.dat
[13:36:06.220] INFO: enter test to run
[13:36:38.043] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:36:38.043] INFO: running: xray
[13:36:38.044] INFO: ----------------------------------------------------------------------
[13:36:38.044] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:36:38.044] INFO: ----------------------------------------------------------------------
[13:36:39.008] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:36:50.324] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:37:19.670] INFO: Resuming triggers.
[13:37:30.984] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:38:00.460] INFO: Resuming triggers.
[13:38:11.778] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:38:41.082] INFO: Resuming triggers.
[13:38:52.400] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:39:21.791] INFO: Resuming triggers.
[13:39:33.106] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:40:02.569] INFO: Resuming triggers.
[13:40:13.881] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:40:43.332] INFO: Resuming triggers.
[13:40:54.648] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:41:24.068] INFO: Resuming triggers.
[13:41:35.383] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:42:04.727] INFO: Resuming triggers.
[13:42:14.536] INFO: data taking finished, elapsed time: 100 seconds.
[13:42:40.088] INFO: PixTest:: pg_setup set to default.
[13:42:40.092] INFO: PixTestXray::doPhRun() done
[13:42:40.229] INFO: enter test to run
[13:43:34.744] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:43:34.744] INFO: running: xray
[13:43:34.745] INFO: ----------------------------------------------------------------------
[13:43:34.745] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:43:34.745] INFO: ----------------------------------------------------------------------
[13:43:35.719] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:43:42.229] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:44:12.310] INFO: Resuming triggers.
[13:44:18.824] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:44:49.048] INFO: Resuming triggers.
[13:44:55.562] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:45:23.663] INFO: Resuming triggers.
[13:45:30.177] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[13:46:00.024] INFO: Resuming triggers.
[13:46:06.538] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:46:36.656] INFO: Resuming triggers.
[13:46:43.169] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:47:13.278] INFO: Resuming triggers.
[13:47:19.792] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:47:49.953] INFO: Resuming triggers.
[13:47:56.468] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:48:26.593] INFO: Resuming triggers.
[13:48:33.110] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:49:03.210] INFO: Resuming triggers.
[13:49:09.727] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:49:39.789] INFO: Resuming triggers.
[13:49:46.307] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:50:16.434] INFO: Resuming triggers.
[13:50:22.948] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:50:52.917] INFO: Resuming triggers.
[13:50:59.435] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:51:29.594] INFO: Resuming triggers.
[13:51:36.110] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:52:06.227] INFO: Resuming triggers.
[13:52:12.743] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[13:52:42.844] INFO: Resuming triggers.
[13:52:45.441] INFO: data taking finished, elapsed time: 100 seconds.
[13:52:57.715] INFO: PixTest:: pg_setup set to default.
[13:52:57.718] INFO: PixTestXray::doPhRun() done
[13:52:57.868] INFO: enter test to run
[13:53:50.868] INFO: test: HighRate no parameter change
[13:53:50.868] INFO: running: highrate
[13:53:50.869] INFO: ----------------------------------------------------------------------
[13:53:50.869] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:53:50.869] INFO: ----------------------------------------------------------------------
[13:53:51.009] INFO: Expecting 768 events.
[13:53:52.143] INFO: 768 events read in total (418ms).
[13:53:52.143] INFO: Test took 1268ms.
[13:53:52.946] INFO: Expecting 41600 events.
[13:53:56.042] INFO: 41600 events read in total (2569ms).
[13:53:56.043] INFO: Test took 3872ms.
[13:53:56.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:56.806] INFO: Expecting 41600 events.
[13:53:59.004] INFO: 41600 events read in total (2671ms).
[13:53:59.005] INFO: Test took 3912ms.
[13:54:00.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:00.765] INFO: Expecting 41600 events.
[13:54:03.001] INFO: 41600 events read in total (2709ms).
[13:54:03.002] INFO: Test took 3944ms.
[13:54:04.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:04.758] INFO: Expecting 41600 events.
[13:54:07.995] INFO: 41600 events read in total (2710ms).
[13:54:07.996] INFO: Test took 3941ms.
[13:54:08.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:08.751] INFO: Expecting 41600 events.
[13:54:11.995] INFO: 41600 events read in total (2717ms).
[13:54:11.996] INFO: Test took 3948ms.
[13:54:12.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:12.756] INFO: Expecting 41600 events.
[13:54:16.012] INFO: 41600 events read in total (2729ms).
[13:54:16.013] INFO: Test took 3963ms.
[13:54:16.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:16.768] INFO: Expecting 41600 events.
[13:54:19.982] INFO: 41600 events read in total (2687ms).
[13:54:19.983] INFO: Test took 3916ms.
[13:54:20.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:20.738] INFO: Expecting 41600 events.
[13:54:23.991] INFO: 41600 events read in total (2726ms).
[13:54:23.992] INFO: Test took 3953ms.
[13:54:24.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:24.749] INFO: Expecting 41600 events.
[13:54:28.011] INFO: 41600 events read in total (2735ms).
[13:54:28.012] INFO: Test took 3966ms.
[13:54:28.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:28.766] INFO: Expecting 41600 events.
[13:54:32.018] INFO: 41600 events read in total (2725ms).
[13:54:32.019] INFO: Test took 3953ms.
[13:54:32.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:32.773] INFO: Expecting 41600 events.
[13:54:36.016] INFO: 41600 events read in total (2716ms).
[13:54:36.017] INFO: Test took 3944ms.
[13:54:36.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:36.773] INFO: Expecting 41600 events.
[13:54:40.027] INFO: 41600 events read in total (2727ms).
[13:54:40.028] INFO: Test took 3957ms.
[13:54:40.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:40.787] INFO: Expecting 41600 events.
[13:54:44.035] INFO: 41600 events read in total (2721ms).
[13:54:44.036] INFO: Test took 3953ms.
[13:54:44.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:44.794] INFO: Expecting 41600 events.
[13:54:48.040] INFO: 41600 events read in total (2719ms).
[13:54:48.041] INFO: Test took 3952ms.
[13:54:48.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:48.798] INFO: Expecting 41600 events.
[13:54:52.058] INFO: 41600 events read in total (2733ms).
[13:54:52.059] INFO: Test took 3965ms.
[13:54:52.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:52.813] INFO: Expecting 41600 events.
[13:54:55.634] INFO: 41600 events read in total (2294ms).
[13:54:55.635] INFO: Test took 3525ms.
[13:54:55.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:56.395] INFO: Expecting 41600 events.
[13:54:59.396] INFO: 41600 events read in total (2474ms).
[13:54:59.397] INFO: Test took 3709ms.
[13:54:59.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:00.157] INFO: Expecting 41600 events.
[13:55:02.973] INFO: 41600 events read in total (2289ms).
[13:55:02.974] INFO: Test took 3522ms.
[13:55:03.010] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:03.734] INFO: Expecting 41600 events.
[13:55:06.548] INFO: 41600 events read in total (2287ms).
[13:55:06.549] INFO: Test took 3521ms.
[13:55:06.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:07.310] INFO: Expecting 41600 events.
[13:55:10.392] INFO: 41600 events read in total (2556ms).
[13:55:10.393] INFO: Test took 3791ms.
[13:55:10.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:10.792] INFO: enter test to run
[13:55:14.907] INFO: test: HighRate no parameter change
[13:55:14.907] INFO: running: highrate
[13:55:14.908] INFO: ----------------------------------------------------------------------
[13:55:14.908] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:55:14.908] INFO: ----------------------------------------------------------------------
[13:55:15.519] INFO: Expecting 208000 events.
[13:55:27.419] INFO: 208000 events read in total (11373ms).
[13:55:27.422] INFO: Test took 12507ms.
[13:55:27.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:27.822] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:55:27.822] INFO: number of red-efficiency pixels: 67 46 84 149 125 125 135 108 86 125 131 110 109 64 24 18
[13:55:27.822] INFO: number of X-ray hits detected: 73376 46024 70952 106043 109652 117461 113194 85569 81759 102989 100088 89637 91710 51843 24098 26613
[13:55:27.822] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:55:27.822] INFO: number of Vcal hits detected: 207930 207954 207914 207847 207872 207873 207860 207890 207913 207873 207864 207887 207887 207936 207976 207982
[13:55:27.822] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[13:55:27.823] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:55:27.823] INFO: X-ray hit rate [MHz/cm2]: 21.5 13.5 20.8 31.1 32.1 34.4 33.2 25.1 24.0 30.2 29.3 26.3 26.9 15.2 7.1 7.8
[13:55:27.823] INFO: PixTestHighRate::doXPixelAlive() done
[13:55:27.871] INFO: PixTest:: pg_setup set to default.
[13:55:27.885] INFO: enter test to run
[13:55:49.499] INFO: test: HighRate no parameter change
[13:55:49.499] INFO: running: highrate
[13:55:49.500] INFO: ----------------------------------------------------------------------
[13:55:49.500] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:55:49.500] INFO: ----------------------------------------------------------------------
[13:55:50.120] INFO: Expecting 208000 events.
[13:56:03.879] INFO: 208000 events read in total (13232ms).
[13:56:03.885] INFO: Test took 14375ms.
[13:56:04.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:04.499] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:56:04.499] INFO: number of red-efficiency pixels: 226 130 342 516 468 443 526 360 220 451 449 389 291 188 45 58
[13:56:04.499] INFO: number of X-ray hits detected: 152524 96049 148789 220491 228044 244485 237337 178289 170575 214813 209300 186993 191304 108414 50442 55883
[13:56:04.499] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:56:04.499] INFO: number of Vcal hits detected: 207745 207865 207620 207420 207492 207524 207434 207608 207768 207515 207510 207584 207703 207804 207952 207942
[13:56:04.500] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[13:56:04.500] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[13:56:04.500] INFO: X-ray hit rate [MHz/cm2]: 44.7 28.2 43.6 64.6 66.8 71.7 69.6 52.3 50.0 63.0 61.3 54.8 56.1 31.8 14.8 16.4
[13:56:04.500] INFO: PixTestHighRate::doXPixelAlive() done
[13:56:04.549] INFO: PixTest:: pg_setup set to default.
[13:56:04.560] INFO: enter test to run
[13:56:23.387] INFO: test: HighRate no parameter change
[13:56:23.387] INFO: running: highrate
[13:56:23.388] INFO: ----------------------------------------------------------------------
[13:56:23.388] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:56:23.388] INFO: ----------------------------------------------------------------------
[13:56:23.002] INFO: Expecting 208000 events.
[13:56:39.755] INFO: 208000 events read in total (15226ms).
[13:56:39.763] INFO: Test took 16366ms.
[13:56:40.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:40.593] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:56:40.593] INFO: number of red-efficiency pixels: 525 294 794 1144 1076 1019 1365 809 492 956 1137 824 671 430 101 122
[13:56:40.593] INFO: number of X-ray hits detected: 229807 145218 223731 333396 345979 368628 359166 270298 258076 324498 315407 282838 289125 164683 76576 84853
[13:56:40.593] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:56:40.593] INFO: number of Vcal hits detected: 207360 207674 206909 206550 206674 206695 206181 206971 207450 206852 206566 206992 207242 207491 207898 207877
[13:56:40.593] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.5 99.4 99.4 99.4 99.2 99.6 99.8 99.5 99.4 99.6 99.7 99.8 100.0 99.9
[13:56:40.593] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.3 99.4 99.4 99.1 99.5 99.7 99.4 99.3 99.5 99.6 99.8 100.0 99.9
[13:56:40.593] INFO: X-ray hit rate [MHz/cm2]: 67.4 42.6 65.6 97.7 101.4 108.0 105.3 79.2 75.6 95.1 92.4 82.9 84.7 48.3 22.4 24.9
[13:56:40.593] INFO: PixTestHighRate::doXPixelAlive() done
[13:56:40.641] INFO: PixTest:: pg_setup set to default.
[13:56:40.655] INFO: enter test to run
[13:56:43.410] INFO: test: exit no parameter change
[13:56:43.740] QUIET: Connection to board 32 closed.
[13:56:43.742] INFO: pXar: this is the end, my friend