[12:41:57.548] INFO: *** Welcome to pxar ***
[12:41:57.548] INFO: *** Today: 2016/10/25
[12:41:58.387] INFO: *** Version: v1.9.0-818-g96727
[12:41:58.387] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//dacParameters35_C15.dat
[12:41:58.424] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:41:58.424] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//defaultMaskFile.dat
[12:41:58.426] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C15.dat
[12:41:58.589] INFO: clk: 4
[12:41:58.590] INFO: ctr: 4
[12:41:58.590] INFO: sda: 19
[12:41:58.590] INFO: tin: 9
[12:41:58.590] INFO: level: 15
[12:41:58.590] INFO: triggerdelay: 0
[12:41:58.590] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:41:58.590] INFO: Log level: INFO
[12:41:58.606] QUIET: Connection to board DTB_WREHUL opened.
[12:41:58.609] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 30
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREHUL
MAC address: 40D85511801E
Hostname: pixelDTB030
Comment:
------------------------------------------------------
[12:41:58.612] INFO: RPC call hashes of host and DTB match: 398089610
[12:42:00.145] INFO: DUT info:
[12:42:00.145] INFO: The DUT currently contains the following objects:
[12:42:00.145] INFO: 2 TBM Cores tbm08c (2 ON)
[12:42:00.145] INFO: TBM Core alpha (0): 7 registers set
[12:42:00.145] INFO: TBM Core beta (1): 7 registers set
[12:42:00.145] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:42:00.145] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.145] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.146] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.146] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.146] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:00.556] INFO: enter 'restricted' command line mode
[12:42:00.556] INFO: enter test to run
[12:42:06.293] INFO: test: PixelAlive no parameter change
[12:42:06.293] INFO: running: pixelalive
[12:42:06.302] INFO: ----------------------------------------------------------------------
[12:42:06.302] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:42:06.302] INFO: ----------------------------------------------------------------------
[12:42:06.625] INFO: Expecting 41600 events.
[12:42:10.947] INFO: 41600 events read in total (3604ms).
[12:42:11.116] INFO: Test took 4811ms.
[12:42:11.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:11.393] INFO: PixTestAlive::aliveTest() done
[12:42:11.393] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 2 2 0 0 1 0 0 0
[12:42:11.425] INFO: enter test to run
[12:42:31.605] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:42:31.605] INFO: running: highrate
[12:42:31.605] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:42:31.812] INFO: ----------------------------------------------------------------------
[12:42:31.812] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:42:31.812] INFO: ----------------------------------------------------------------------
[12:42:31.812] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:42:31.812] INFO: edge/corner pixel THR is adjusted
[12:42:31.812] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:42:32.771] INFO: Collecting data for 5 seconds...
[12:42:37.790] INFO: Done with hot pixel readout
[12:42:49.180] INFO: PixTest:: pg_setup set to default.
[12:42:49.180] INFO: 8 hot pixels found in step 0
[12:42:50.189] INFO: Collecting data for 5 seconds...
[12:42:55.207] INFO: Done with hot pixel readout
[12:43:07.095] INFO: PixTest:: pg_setup set to default.
[12:43:07.096] INFO: 9 hot pixels found in step 1
[12:43:08.087] INFO: Collecting data for 5 seconds...
[12:43:13.105] INFO: Done with hot pixel readout
[12:43:25.008] INFO: PixTest:: pg_setup set to default.

[12:43:25.009] INFO: 11 hot pixels found in step 2
[12:43:25.000] INFO: Collecting data for 5 seconds...
[12:43:31.018] INFO: Done with hot pixel readout
[12:43:42.769] INFO: PixTest:: pg_setup set to default.

[12:43:42.769] INFO: 10 hot pixels found in step 3
[12:43:43.761] INFO: Collecting data for 5 seconds...
[12:43:48.779] INFO: Done with hot pixel readout
[12:44:00.607] INFO: PixTest:: pg_setup set to default.

[12:44:00.608] INFO: 8 hot pixels found in step 4
[12:44:01.600] INFO: Collecting data for 5 seconds...
[12:44:06.619] INFO: Done with hot pixel readout
[12:44:18.374] INFO: PixTest:: pg_setup set to default.

[12:44:18.375] INFO: 8 hot pixels found in step 5
[12:44:19.367] INFO: Collecting data for 5 seconds...
[12:44:24.386] INFO: Done with hot pixel readout
[12:44:36.241] INFO: PixTest:: pg_setup set to default.


[12:44:36.242] INFO: 11 hot pixels found in step 6
[12:44:37.233] INFO: Collecting data for 5 seconds...
[12:44:42.252] INFO: Done with hot pixel readout
[12:44:53.941] INFO: PixTest:: pg_setup set to default.


[12:44:53.942] INFO: 5 hot pixels found in step 7
[12:44:54.933] INFO: Collecting data for 5 seconds...
[12:44:59.953] INFO: Done with hot pixel readout
[12:45:11.604] INFO: PixTest:: pg_setup set to default.


[12:45:11.605] INFO: 5 hot pixels found in step 8
[12:45:12.595] INFO: Collecting data for 5 seconds...
[12:45:17.616] INFO: Done with hot pixel readout
[12:45:29.133] INFO: PixTest:: pg_setup set to default.


[12:45:29.133] INFO: 2 hot pixels found in step 9
[12:45:29.168] INFO: 2 hot pixels could not be trimmed and have been masked.
[12:45:29.172] INFO: PixTest::trimHotPixels() done
[12:45:29.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C0.dat
[12:45:29.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C1.dat
[12:45:29.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C2.dat
[12:45:29.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C3.dat
[12:45:29.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C4.dat
[12:45:29.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C5.dat
[12:45:29.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C6.dat
[12:45:29.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C7.dat
[12:45:29.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C8.dat
[12:45:29.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C9.dat
[12:45:29.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C10.dat
[12:45:29.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C11.dat
[12:45:29.256] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C12.dat
[12:45:29.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C13.dat
[12:45:29.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C14.dat
[12:45:29.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C15.dat
[12:45:29.278] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//defaultMaskFile.dat
[12:45:29.295] INFO: enter test to run
[12:47:31.211] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:47:31.211] INFO: running: highrate
[12:47:31.215] INFO: ----------------------------------------------------------------------
[12:47:31.215] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:47:31.215] INFO: ----------------------------------------------------------------------
[12:47:31.215] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:47:31.215] INFO: edge/corner pixel THR is adjusted
[12:47:31.215] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:47:32.173] INFO: Collecting data for 1 seconds...
[12:47:33.176] INFO: Done with hot pixel readout
[12:47:36.002] INFO: PixTest:: pg_setup set to default.
[12:47:36.002] INFO: 0 hot pixels found in step 0
[12:47:37.008] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:47:37.107] INFO: PixTest::trimHotPixels() done
[12:47:37.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C0.dat
[12:47:37.116] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C1.dat
[12:47:37.122] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C2.dat
[12:47:37.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C3.dat
[12:47:37.133] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C4.dat
[12:47:37.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C5.dat
[12:47:37.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C6.dat
[12:47:37.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C7.dat
[12:47:37.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C8.dat
[12:47:37.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C9.dat
[12:47:37.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C10.dat
[12:47:37.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C11.dat
[12:47:37.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C12.dat
[12:47:37.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C13.dat
[12:47:37.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C14.dat
[12:47:37.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C15.dat
[12:47:37.196] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-41_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//defaultMaskFile.dat
[12:47:37.213] INFO: enter test to run
[12:47:56.842] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:47:56.842] INFO: running: xray
[12:47:56.844] INFO: ----------------------------------------------------------------------
[12:47:56.844] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:47:56.844] INFO: ----------------------------------------------------------------------
[12:47:57.808] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:48:09.855] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:48:39.131] INFO: Resuming triggers.
[12:48:51.182] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[12:49:20.615] INFO: Resuming triggers.
[12:49:32.667] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:50:01.995] INFO: Resuming triggers.
[12:50:14.044] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[12:50:43.352] INFO: Resuming triggers.
[12:50:55.405] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:51:24.743] INFO: Resuming triggers.
[12:51:36.797] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:52:06.110] INFO: Resuming triggers.
[12:52:18.165] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[12:52:47.920] INFO: Resuming triggers.
[12:52:59.975] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[12:53:28.898] INFO: Resuming triggers.
[12:53:32.824] INFO: data taking finished, elapsed time: 100 seconds.
[12:53:42.844] INFO: PixTest:: pg_setup set to default.
[12:53:42.847] INFO: PixTestXray::doPhRun() done
[12:53:42.983] INFO: enter test to run
[12:54:18.144] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:54:18.144] INFO: running: xray
[12:54:18.145] INFO: ----------------------------------------------------------------------
[12:54:18.145] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:54:18.145] INFO: ----------------------------------------------------------------------
[12:54:19.108] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:54:26.247] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:54:57.072] INFO: Resuming triggers.
[12:55:04.211] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:55:35.280] INFO: Resuming triggers.
[12:55:42.419] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:56:13.187] INFO: Resuming triggers.
[12:56:20.326] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:56:51.441] INFO: Resuming triggers.
[12:56:58.577] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:57:30.285] INFO: Resuming triggers.
[12:57:37.419] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:58:08.879] INFO: Resuming triggers.
[12:58:16.015] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:58:46.917] INFO: Resuming triggers.
[12:58:54.051] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:59:25.505] INFO: Resuming triggers.
[12:59:32.643] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:00:03.328] INFO: Resuming triggers.
[13:00:10.464] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:00:40.557] INFO: Resuming triggers.
[13:00:47.692] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:01:17.807] INFO: Resuming triggers.
[13:01:24.946] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:01:55.098] INFO: Resuming triggers.
[13:02:02.238] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:02:32.414] INFO: Resuming triggers.
[13:02:39.555] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:03:09.751] INFO: Resuming triggers.
[13:03:10.189] INFO: data taking finished, elapsed time: 100 seconds.
[13:03:12.365] INFO: PixTest:: pg_setup set to default.
[13:03:12.368] INFO: PixTestXray::doPhRun() done
[13:03:12.548] INFO: enter test to run
[13:03:57.828] INFO: test: HighRate no parameter change
[13:03:57.828] INFO: running: highrate
[13:03:57.850] INFO: ----------------------------------------------------------------------
[13:03:57.850] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:03:57.850] INFO: ----------------------------------------------------------------------
[13:03:57.005] INFO: Expecting 768 events.
[13:03:59.139] INFO: 768 events read in total (418ms).
[13:03:59.139] INFO: Test took 1268ms.
[13:03:59.942] INFO: Expecting 41600 events.
[13:04:02.893] INFO: 41600 events read in total (2424ms).
[13:04:02.895] INFO: Test took 3731ms.
[13:04:02.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:03.657] INFO: Expecting 41600 events.
[13:04:06.787] INFO: 41600 events read in total (2603ms).
[13:04:06.788] INFO: Test took 3842ms.
[13:04:06.818] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:07.551] INFO: Expecting 41600 events.
[13:04:10.752] INFO: 41600 events read in total (2674ms).
[13:04:10.753] INFO: Test took 3918ms.
[13:04:10.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:11.517] INFO: Expecting 41600 events.
[13:04:14.723] INFO: 41600 events read in total (2679ms).
[13:04:14.724] INFO: Test took 3925ms.
[13:04:14.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:15.486] INFO: Expecting 41600 events.
[13:04:18.693] INFO: 41600 events read in total (2680ms).
[13:04:18.694] INFO: Test took 3922ms.
[13:04:18.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:19.457] INFO: Expecting 41600 events.
[13:04:22.642] INFO: 41600 events read in total (2658ms).
[13:04:22.643] INFO: Test took 3901ms.
[13:04:22.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:23.405] INFO: Expecting 41600 events.
[13:04:26.599] INFO: 41600 events read in total (2667ms).
[13:04:26.600] INFO: Test took 3910ms.
[13:04:26.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:27.360] INFO: Expecting 41600 events.
[13:04:30.571] INFO: 41600 events read in total (2685ms).
[13:04:30.572] INFO: Test took 3925ms.
[13:04:30.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:31.331] INFO: Expecting 41600 events.
[13:04:34.532] INFO: 41600 events read in total (2674ms).
[13:04:34.533] INFO: Test took 3915ms.
[13:04:34.563] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:35.293] INFO: Expecting 41600 events.
[13:04:38.503] INFO: 41600 events read in total (2683ms).
[13:04:38.504] INFO: Test took 3924ms.
[13:04:38.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:39.262] INFO: Expecting 41600 events.
[13:04:42.462] INFO: 41600 events read in total (2673ms).
[13:04:42.463] INFO: Test took 3911ms.
[13:04:42.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:43.222] INFO: Expecting 41600 events.
[13:04:46.424] INFO: 41600 events read in total (2675ms).
[13:04:46.425] INFO: Test took 3915ms.
[13:04:46.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:47.185] INFO: Expecting 41600 events.
[13:04:50.383] INFO: 41600 events read in total (2671ms).
[13:04:50.384] INFO: Test took 3912ms.
[13:04:50.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:51.143] INFO: Expecting 41600 events.
[13:04:54.346] INFO: 41600 events read in total (2676ms).
[13:04:54.347] INFO: Test took 3915ms.
[13:04:54.379] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:55.109] INFO: Expecting 41600 events.
[13:04:58.294] INFO: 41600 events read in total (2658ms).
[13:04:58.296] INFO: Test took 3900ms.
[13:04:58.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:59.058] INFO: Expecting 41600 events.
[13:05:02.263] INFO: 41600 events read in total (2678ms).
[13:05:02.263] INFO: Test took 3913ms.
[13:05:02.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:03.022] INFO: Expecting 41600 events.
[13:05:06.237] INFO: 41600 events read in total (2688ms).
[13:05:06.237] INFO: Test took 3926ms.
[13:05:06.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:06.999] INFO: Expecting 41600 events.
[13:05:10.208] INFO: 41600 events read in total (2682ms).
[13:05:10.209] INFO: Test took 3924ms.
[13:05:10.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:10.969] INFO: Expecting 41600 events.
[13:05:14.160] INFO: 41600 events read in total (2664ms).
[13:05:14.161] INFO: Test took 3905ms.
[13:05:14.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:14.924] INFO: Expecting 41600 events.
[13:05:18.044] INFO: 41600 events read in total (2593ms).
[13:05:18.045] INFO: Test took 3837ms.
[13:05:18.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:18.445] INFO: enter test to run
[13:05:57.731] INFO: test: HighRate no parameter change
[13:05:57.731] INFO: running: highrate
[13:05:57.732] INFO: ----------------------------------------------------------------------
[13:05:57.732] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:05:57.732] INFO: ----------------------------------------------------------------------
[13:05:58.347] INFO: Expecting 208000 events.
[13:06:09.002] INFO: 208000 events read in total (11128ms).
[13:06:09.005] INFO: Test took 12264ms.
[13:06:10.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:10.380] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 2 2 0 0 1 0 0 0
[13:06:10.380] INFO: number of red-efficiency pixels: 69 42 59 91 99 111 121 85 75 118 102 85 93 50 16 14
[13:06:10.380] INFO: number of X-ray hits detected: 59927 38155 56516 86071 91372 99943 97549 63358 63627 93450 89324 72637 75534 45828 19226 20019
[13:06:10.380] 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:06:10.380] INFO: number of Vcal hits detected: 207929 207957 207939 207908 207899 207886 207879 207915 207827 207782 207896 207913 207857 207943 207984 207986
[13:06:10.380] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[13:06:10.380] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[13:06:10.380] INFO: X-ray hit rate [MHz/cm2]: 17.6 11.2 16.6 25.2 26.8 29.3 28.6 18.6 18.6 27.4 26.2 21.3 22.1 13.4 5.6 5.9
[13:06:10.380] INFO: PixTestHighRate::doXPixelAlive() done
[13:06:10.434] INFO: PixTest:: pg_setup set to default.
[13:06:10.446] INFO: enter test to run
[13:07:07.515] INFO: test: HighRate no parameter change
[13:07:07.515] INFO: running: highrate
[13:07:07.516] INFO: ----------------------------------------------------------------------
[13:07:07.516] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:07:07.516] INFO: ----------------------------------------------------------------------
[13:07:08.136] INFO: Expecting 208000 events.
[13:07:21.553] INFO: 208000 events read in total (12890ms).
[13:07:21.558] INFO: Test took 14033ms.
[13:07:21.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:22.134] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 2 2 0 0 1 0 0 0
[13:07:22.134] INFO: number of red-efficiency pixels: 190 133 234 337 302 302 484 259 215 340 378 268 257 135 65 61
[13:07:22.134] INFO: number of X-ray hits detected: 132540 83783 126791 192310 201482 218124 215761 140243 142007 208165 197479 159594 166927 102001 42215 44929
[13:07:22.134] 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:07:22.134] INFO: number of Vcal hits detected: 207796 207859 207744 207638 207674 207682 207468 207721 207677 207539 207607 207715 207681 207852 207933 207938
[13:07:22.134] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.9 99.9 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:07:22.134] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[13:07:22.134] INFO: X-ray hit rate [MHz/cm2]: 38.8 24.6 37.2 56.4 59.1 63.9 63.2 41.1 41.6 61.0 57.9 46.8 48.9 29.9 12.4 13.2
[13:07:22.134] INFO: PixTestHighRate::doXPixelAlive() done
[13:07:22.179] INFO: PixTest:: pg_setup set to default.
[13:07:22.194] INFO: enter test to run
[13:07:38.146] INFO: test: HighRate no parameter change
[13:07:38.147] INFO: running: highrate
[13:07:38.148] INFO: ----------------------------------------------------------------------
[13:07:38.148] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:07:38.148] INFO: ----------------------------------------------------------------------
[13:07:38.764] INFO: Expecting 208000 events.
[13:07:53.811] INFO: 208000 events read in total (14520ms).
[13:07:53.818] INFO: Test took 15662ms.
[13:07:54.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:54.567] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 2 2 0 0 1 0 0 0
[13:07:54.567] INFO: number of red-efficiency pixels: 390 228 501 745 621 761 959 465 484 671 855 589 477 256 102 72
[13:07:54.567] INFO: number of X-ray hits detected: 196060 125240 187139 282785 298941 323839 318345 208104 210832 307787 292870 236821 247590 151138 63126 66435
[13:07:54.567] 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:07:54.567] INFO: number of Vcal hits detected: 207541 207758 207384 207147 207312 207104 206832 207446 207363 207124 207002 207331 207421 207719 207893 207928
[13:07:54.567] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.7 99.6 99.5 99.8 99.8 99.7 99.6 99.7 99.8 99.9 99.9 100.0
[13:07:54.567] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.6 99.7 99.6 99.4 99.7 99.7 99.6 99.5 99.7 99.7 99.9 99.9 100.0
[13:07:54.567] INFO: X-ray hit rate [MHz/cm2]: 57.5 36.7 54.9 82.9 87.6 94.9 93.3 61.0 61.8 90.2 85.8 69.4 72.6 44.3 18.5 19.5
[13:07:54.567] INFO: PixTestHighRate::doXPixelAlive() done
[13:07:54.614] INFO: PixTest:: pg_setup set to default.
[13:07:54.628] INFO: enter test to run
[13:07:58.754] INFO: test: exit no parameter change
[13:07:59.387] QUIET: Connection to board 30 closed.
[13:07:59.395] INFO: pXar: this is the end, my friend