[12:15:39.780] INFO: *** Welcome to pxar ***
[12:15:39.780] INFO: *** Today: 2016/06/23
[12:15:39.826] INFO: *** Version: v1.9.0-814-g7497
[12:15:39.826] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//dacParameters35_C15.dat
[12:15:39.873] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:15:39.873] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[12:15:39.874] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[12:15:39.968] INFO: clk: 4
[12:15:39.968] INFO: ctr: 4
[12:15:39.968] INFO: sda: 19
[12:15:39.968] INFO: tin: 9
[12:15:39.968] INFO: level: 15
[12:15:39.968] INFO: triggerdelay: 0
[12:15:39.968] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:15:39.968] INFO: Log level: INFO
[12:15:39.987] QUIET: Connection to board DTB_WREK4U opened.
[12:15:39.990] 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:
------------------------------------------------------
[12:15:39.993] INFO: RPC call hashes of host and DTB match: 398089610
[12:15:41.524] INFO: DUT info:
[12:15:41.524] INFO: The DUT currently contains the following objects:
[12:15:41.524] INFO: 2 TBM Cores tbm08c (2 ON)
[12:15:41.524] INFO: TBM Core alpha (0): 7 registers set
[12:15:41.524] INFO: TBM Core beta (1): 7 registers set
[12:15:41.524] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:15:41.524] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.524] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.525] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.525] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.525] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.525] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.525] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.525] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:41.928] INFO: enter 'restricted' command line mode
[12:15:41.928] INFO: enter test to run
[12:15:47.967] INFO: test: PixelAlive no parameter change
[12:15:47.967] INFO: running: pixelalive
[12:15:47.976] INFO: ----------------------------------------------------------------------
[12:15:47.976] 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:15:47.976] INFO: ----------------------------------------------------------------------
[12:15:48.294] INFO: Expecting 41600 events.
[12:15:52.634] INFO: 41600 events read in total (3621ms).
[12:15:52.801] INFO: Test took 4821ms.
[12:15:52.814] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:53.077] INFO: PixTestAlive::aliveTest() done
[12:15:53.077] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:15:53.109] INFO: enter test to run
[12:18:14.326] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:18:14.326] INFO: running: highrate
[12:18:14.326] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:18:14.567] INFO: ----------------------------------------------------------------------
[12:18:14.567] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:18:14.567] INFO: ----------------------------------------------------------------------
[12:18:14.567] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:18:14.567] INFO: edge/corner pixel THR is adjusted
[12:18:14.567] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:18:15.527] INFO: Collecting data for 5 seconds...
[12:18:20.544] INFO: Done with hot pixel readout
[12:18:31.809] INFO: PixTest:: pg_setup set to default.
[12:18:31.809] INFO: 11 hot pixels found in step 0
[12:18:32.819] INFO: Collecting data for 5 seconds...
[12:18:37.836] INFO: Done with hot pixel readout
[12:18:49.078] INFO: PixTest:: pg_setup set to default.
[12:18:49.079] INFO: 11 hot pixels found in step 1
[12:18:50.064] INFO: Collecting data for 5 seconds...
[12:18:55.081] INFO: Done with hot pixel readout
[12:19:06.337] INFO: PixTest:: pg_setup set to default.

[12:19:06.338] INFO: 10 hot pixels found in step 2
[12:19:07.323] INFO: Collecting data for 5 seconds...
[12:19:12.341] INFO: Done with hot pixel readout
[12:19:23.573] INFO: PixTest:: pg_setup set to default.

[12:19:23.574] INFO: 9 hot pixels found in step 3
[12:19:24.559] INFO: Collecting data for 5 seconds...
[12:19:29.577] INFO: Done with hot pixel readout
[12:19:40.687] INFO: PixTest:: pg_setup set to default.

[12:19:40.688] INFO: 10 hot pixels found in step 4
[12:19:41.673] INFO: Collecting data for 5 seconds...
[12:19:46.693] INFO: Done with hot pixel readout
[12:19:57.788] INFO: PixTest:: pg_setup set to default.

[12:19:57.789] INFO: 10 hot pixels found in step 5
[12:19:58.774] INFO: Collecting data for 5 seconds...
[12:20:03.792] INFO: Done with hot pixel readout
[12:20:15.069] INFO: PixTest:: pg_setup set to default.



[12:20:15.070] INFO: 10 hot pixels found in step 6
[12:20:16.054] INFO: Collecting data for 5 seconds...
[12:20:21.072] INFO: Done with hot pixel readout
[12:20:32.182] INFO: PixTest:: pg_setup set to default.



[12:20:32.183] INFO: 6 hot pixels found in step 7
[12:20:33.167] INFO: Collecting data for 5 seconds...
[12:20:38.186] INFO: Done with hot pixel readout
[12:20:49.317] INFO: PixTest:: pg_setup set to default.




[12:20:49.318] INFO: 8 hot pixels found in step 8
[12:20:50.303] INFO: Collecting data for 5 seconds...
[12:20:55.319] INFO: Done with hot pixel readout
[12:21:06.358] INFO: PixTest:: pg_setup set to default.






[12:21:06.359] INFO: 7 hot pixels found in step 9
[12:21:07.344] INFO: Collecting data for 5 seconds...
[12:21:12.361] INFO: Done with hot pixel readout
[12:21:23.694] INFO: PixTest:: pg_setup set to default.





[12:21:23.695] INFO: 8 hot pixels found in step 10
[12:21:24.680] INFO: Collecting data for 5 seconds...
[12:21:29.699] INFO: Done with hot pixel readout
[12:21:41.061] INFO: PixTest:: pg_setup set to default.






[12:21:41.062] INFO: 6 hot pixels found in step 11
[12:21:41.091] INFO: 6 hot pixels could not be trimmed and have been masked.
[12:21:41.095] INFO: PixTest::trimHotPixels() done
[12:21:41.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat
[12:21:41.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C1.dat
[12:21:41.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C2.dat
[12:21:41.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C3.dat
[12:21:41.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C4.dat
[12:21:41.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C5.dat
[12:21:41.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C6.dat
[12:21:41.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C7.dat
[12:21:41.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C8.dat
[12:21:41.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C9.dat
[12:21:41.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C10.dat
[12:21:41.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C11.dat
[12:21:41.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C12.dat
[12:21:41.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C13.dat
[12:21:41.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C14.dat
[12:21:41.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[12:21:41.182] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[12:21:41.193] INFO: enter test to run
[12:22:48.156] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:22:48.156] INFO: running: highrate
[12:22:48.161] INFO: ----------------------------------------------------------------------
[12:22:48.161] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:22:48.161] INFO: ----------------------------------------------------------------------
[12:22:48.161] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:22:48.161] INFO: edge/corner pixel THR is adjusted
[12:22:48.161] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:22:49.125] INFO: Collecting data for 1 seconds...
[12:22:50.129] INFO: Done with hot pixel readout
[12:22:53.950] INFO: PixTest:: pg_setup set to default.
[12:22:53.951] INFO: 0 hot pixels found in step 0
[12:22:53.957] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:22:54.055] INFO: PixTest::trimHotPixels() done
[12:22:54.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat
[12:22:54.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C1.dat
[12:22:54.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C2.dat
[12:22:54.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C3.dat
[12:22:54.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C4.dat
[12:22:54.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C5.dat
[12:22:54.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C6.dat
[12:22:54.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C7.dat
[12:22:54.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C8.dat
[12:22:54.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C9.dat
[12:22:54.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C10.dat
[12:22:54.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C11.dat
[12:22:54.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C12.dat
[12:22:54.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C13.dat
[12:22:54.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C14.dat
[12:22:54.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[12:22:54.141] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-3-17_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[12:22:54.150] INFO: enter test to run
[12:23:33.916] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:23:33.916] INFO: running: xray
[12:23:33.917] INFO: ----------------------------------------------------------------------
[12:23:33.917] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:23:33.917] INFO: ----------------------------------------------------------------------
[12:23:34.880] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:23:46.801] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:24:15.867] INFO: Resuming triggers.
[12:24:27.790] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:24:57.054] INFO: Resuming triggers.
[12:25:08.975] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:25:38.109] INFO: Resuming triggers.
[12:25:50.032] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:26:19.105] INFO: Resuming triggers.
[12:26:31.022] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:27:00.131] INFO: Resuming triggers.
[12:27:12.048] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:27:41.194] INFO: Resuming triggers.
[12:27:53.108] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:28:22.271] INFO: Resuming triggers.
[12:28:34.185] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:29:03.453] INFO: Resuming triggers.
[12:29:08.422] INFO: data taking finished, elapsed time: 100 seconds.
[12:29:20.851] INFO: PixTest:: pg_setup set to default.
[12:29:20.854] INFO: PixTestXray::doPhRun() done
[12:29:20.988] INFO: enter test to run
[12:30:19.873] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:30:19.873] INFO: running: xray
[12:30:19.874] INFO: ----------------------------------------------------------------------
[12:30:19.874] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:30:19.874] INFO: ----------------------------------------------------------------------
[12:30:20.838] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:30:28.129] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:30:58.266] INFO: Resuming triggers.
[12:31:05.561] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:31:36.360] INFO: Resuming triggers.
[12:31:43.654] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:32:14.426] INFO: Resuming triggers.
[12:32:21.720] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[12:32:52.385] INFO: Resuming triggers.
[12:32:59.682] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:33:31.030] INFO: Resuming triggers.
[12:33:38.325] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:34:09.262] INFO: Resuming triggers.
[12:34:16.560] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:34:47.038] INFO: Resuming triggers.
[12:34:54.336] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:35:24.396] INFO: Resuming triggers.
[12:35:31.691] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:36:01.751] INFO: Resuming triggers.
[12:36:09.045] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:36:39.101] INFO: Resuming triggers.
[12:36:46.395] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:37:16.516] INFO: Resuming triggers.
[12:37:23.810] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:37:53.897] INFO: Resuming triggers.
[12:38:01.193] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:38:31.285] INFO: Resuming triggers.
[12:38:36.796] INFO: data taking finished, elapsed time: 100 seconds.
[12:38:59.852] INFO: PixTest:: pg_setup set to default.
[12:38:59.856] INFO: PixTestXray::doPhRun() done
[12:39:00.002] INFO: enter test to run
[12:39:31.037] INFO: test: HighRate no parameter change
[12:39:31.037] INFO: running: highrate
[12:39:31.038] INFO: ----------------------------------------------------------------------
[12:39:31.038] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:39:31.038] INFO: ----------------------------------------------------------------------
[12:39:31.179] INFO: Expecting 768 events.
[12:39:32.313] INFO: 768 events read in total (418ms).
[12:39:32.314] INFO: Test took 1269ms.
[12:39:33.116] INFO: Expecting 41600 events.
[12:39:36.187] INFO: 41600 events read in total (2544ms).
[12:39:36.188] INFO: Test took 3867ms.
[12:39:36.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:36.953] INFO: Expecting 41600 events.
[12:39:40.139] INFO: 41600 events read in total (2659ms).
[12:39:40.140] INFO: Test took 3907ms.
[12:39:40.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:40.903] INFO: Expecting 41600 events.
[12:39:44.107] INFO: 41600 events read in total (2678ms).
[12:39:44.108] INFO: Test took 3920ms.
[12:39:44.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:44.867] INFO: Expecting 41600 events.
[12:39:48.055] INFO: 41600 events read in total (2661ms).
[12:39:48.056] INFO: Test took 3901ms.
[12:39:48.087] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:48.814] INFO: Expecting 41600 events.
[12:39:52.004] INFO: 41600 events read in total (2663ms).
[12:39:52.004] INFO: Test took 3899ms.
[12:39:52.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:52.765] INFO: Expecting 41600 events.
[12:39:55.962] INFO: 41600 events read in total (2670ms).
[12:39:55.963] INFO: Test took 3912ms.
[12:39:55.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:56.721] INFO: Expecting 41600 events.
[12:39:59.912] INFO: 41600 events read in total (2664ms).
[12:39:59.913] INFO: Test took 3902ms.
[12:39:59.944] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:00.674] INFO: Expecting 41600 events.
[12:40:03.887] INFO: 41600 events read in total (2686ms).
[12:40:03.888] INFO: Test took 3927ms.
[12:40:03.918] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:04.650] INFO: Expecting 41600 events.
[12:40:07.846] INFO: 41600 events read in total (2669ms).
[12:40:07.847] INFO: Test took 3913ms.
[12:40:07.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:08.608] INFO: Expecting 41600 events.
[12:40:11.807] INFO: 41600 events read in total (2672ms).
[12:40:11.808] INFO: Test took 3914ms.
[12:40:11.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:12.570] INFO: Expecting 41600 events.
[12:40:15.767] INFO: 41600 events read in total (2670ms).
[12:40:15.768] INFO: Test took 3913ms.
[12:40:15.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:16.532] INFO: Expecting 41600 events.
[12:40:19.735] INFO: 41600 events read in total (2676ms).
[12:40:19.736] INFO: Test took 3920ms.
[12:40:19.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:20.495] INFO: Expecting 41600 events.
[12:40:23.661] INFO: 41600 events read in total (2639ms).
[12:40:23.662] INFO: Test took 3878ms.
[12:40:23.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:24.425] INFO: Expecting 41600 events.
[12:40:27.633] INFO: 41600 events read in total (2681ms).
[12:40:27.634] INFO: Test took 3926ms.
[12:40:27.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:28.395] INFO: Expecting 41600 events.
[12:40:31.570] INFO: 41600 events read in total (2648ms).
[12:40:31.571] INFO: Test took 3890ms.
[12:40:31.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:32.334] INFO: Expecting 41600 events.
[12:40:35.530] INFO: 41600 events read in total (2669ms).
[12:40:35.531] INFO: Test took 3914ms.
[12:40:35.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:36.293] INFO: Expecting 41600 events.
[12:40:39.491] INFO: 41600 events read in total (2671ms).
[12:40:39.492] INFO: Test took 3914ms.
[12:40:39.522] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:40.255] INFO: Expecting 41600 events.
[12:40:43.459] INFO: 41600 events read in total (2677ms).
[12:40:43.460] INFO: Test took 3920ms.
[12:40:43.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:44.219] INFO: Expecting 41600 events.
[12:40:47.400] INFO: 41600 events read in total (2654ms).
[12:40:47.401] INFO: Test took 3893ms.
[12:40:47.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:48.164] INFO: Expecting 41600 events.
[12:40:51.210] INFO: 41600 events read in total (2519ms).
[12:40:51.211] INFO: Test took 3762ms.
[12:40:51.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:51.611] INFO: enter test to run
[12:40:58.036] INFO: test: HighRate no parameter change
[12:40:58.036] INFO: running: highrate
[12:40:58.038] INFO: ----------------------------------------------------------------------
[12:40:58.038] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:40:58.038] INFO: ----------------------------------------------------------------------
[12:40:58.648] INFO: Expecting 208000 events.
[12:41:10.323] INFO: 208000 events read in total (11148ms).
[12:41:10.326] INFO: Test took 12282ms.
[12:41:10.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:10.699] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:41:10.699] INFO: number of red-efficiency pixels: 63 42 57 108 125 121 131 66 74 100 104 86 89 44 22 28
[12:41:10.699] INFO: number of X-ray hits detected: 62610 40207 57482 89663 94986 93421 96771 68762 65299 85215 85010 74111 76360 46672 21469 24442
[12:41:10.699] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:41:10.699] INFO: number of Vcal hits detected: 207936 207957 207943 207891 207872 207876 207868 207932 207924 207899 207894 207912 207907 207956 207978 207972
[12:41:10.699] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[12:41:10.699] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[12:41:10.699] INFO: X-ray hit rate [MHz/cm2]: 18.4 11.8 16.8 26.3 27.8 27.4 28.4 20.2 19.1 25.0 24.9 21.7 22.4 13.7 6.3 7.2
[12:41:10.699] INFO: PixTestHighRate::doXPixelAlive() done
[12:41:10.747] INFO: PixTest:: pg_setup set to default.
[12:41:10.758] INFO: enter test to run
[12:41:37.884] INFO: test: HighRate no parameter change
[12:41:37.884] INFO: running: highrate
[12:41:37.885] INFO: ----------------------------------------------------------------------
[12:41:37.885] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:41:37.885] INFO: ----------------------------------------------------------------------
[12:41:38.502] INFO: Expecting 208000 events.
[12:41:51.620] INFO: 208000 events read in total (12591ms).
[12:41:51.625] INFO: Test took 13731ms.
[12:41:51.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:52.169] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:41:52.169] INFO: number of red-efficiency pixels: 175 109 177 336 387 359 382 203 209 253 334 230 304 144 37 45
[12:41:52.169] INFO: number of X-ray hits detected: 128126 82854 118638 184882 195956 193784 200229 142303 134886 175518 174539 152296 159030 95775 44448 51034
[12:41:52.169] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:41:52.169] INFO: number of Vcal hits detected: 207814 207881 207817 207650 207589 207615 207593 207787 207784 207732 207643 207762 207684 207853 207963 207955
[12:41:52.169] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[12:41:52.169] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.8 99.9 100.0 100.0
[12:41:52.169] INFO: X-ray hit rate [MHz/cm2]: 37.6 24.3 34.8 54.2 57.4 56.8 58.7 41.7 39.5 51.4 51.2 44.6 46.6 28.1 13.0 15.0
[12:41:52.169] INFO: PixTestHighRate::doXPixelAlive() done
[12:41:52.218] INFO: PixTest:: pg_setup set to default.
[12:41:52.231] INFO: enter test to run
[12:42:12.276] INFO: test: HighRate no parameter change
[12:42:12.276] INFO: running: highrate
[12:42:12.277] INFO: ----------------------------------------------------------------------
[12:42:12.277] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:42:12.277] INFO: ----------------------------------------------------------------------
[12:42:12.894] INFO: Expecting 208000 events.
[12:42:27.575] INFO: 208000 events read in total (14154ms).
[12:42:27.581] INFO: Test took 15293ms.
[12:42:27.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:28.284] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:42:28.285] INFO: number of red-efficiency pixels: 360 189 379 736 861 844 964 531 457 511 703 455 591 308 89 84
[12:42:28.285] INFO: number of X-ray hits detected: 193799 125258 179110 279471 296609 292729 303546 215523 203467 266636 262632 230371 240274 144918 66869 77050
[12:42:28.285] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:42:28.285] INFO: number of Vcal hits detected: 207564 207804 207563 207147 206997 206996 206844 207381 207503 207434 207201 207516 207344 207672 207909 207915
[12:42:28.285] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.5 99.7 99.8 99.7 99.6 99.8 99.7 99.9 100.0 100.0
[12:42:28.285] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.5 99.4 99.7 99.8 99.7 99.6 99.8 99.7 99.8 100.0 100.0
[12:42:28.285] INFO: X-ray hit rate [MHz/cm2]: 56.8 36.7 52.5 81.9 86.9 85.8 89.0 63.2 59.6 78.2 77.0 67.5 70.4 42.5 19.6 22.6
[12:42:28.285] INFO: PixTestHighRate::doXPixelAlive() done
[12:42:28.336] INFO: PixTest:: pg_setup set to default.
[12:42:28.356] INFO: enter test to run
[12:42:54.228] INFO: test: exit no parameter change
[12:42:54.544] QUIET: Connection to board 32 closed.
[12:42:54.545] INFO: pXar: this is the end, my friend