[14:18:21.536] INFO: *** Welcome to pxar ***
[14:18:21.536] INFO: *** Today: 2016/04/13
[14:18:21.649] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:18:21.649] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//dacParameters35_C15.dat
[14:18:21.652] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:18:21.652] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//defaultMaskFile.dat
[14:18:21.668] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C15.dat
[14:18:21.752] INFO: clk: 4
[14:18:21.752] INFO: ctr: 4
[14:18:21.752] INFO: sda: 19
[14:18:21.752] INFO: tin: 9
[14:18:21.752] INFO: level: 15
[14:18:21.752] INFO: triggerdelay: 0
[14:18:21.753] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:18:21.753] INFO: Log level: INFO
[14:18:21.770] QUIET: Connection to board DTB_WREKRL opened.
[14:18:21.774] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[14:18:21.777] INFO: RPC call hashes of host and DTB match: 398089610
[14:18:23.308] INFO: DUT info:
[14:18:23.308] INFO: The DUT currently contains the following objects:
[14:18:23.308] INFO: 2 TBM Cores tbm08c (2 ON)
[14:18:23.308] INFO: TBM Core alpha (0): 7 registers set
[14:18:23.308] INFO: TBM Core beta (1): 7 registers set
[14:18:23.308] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:18:23.308] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.308] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:23.712] INFO: enter 'restricted' command line mode
[14:18:23.712] INFO: enter test to run
[14:22:01.725] INFO: test: PixelAlive no parameter change
[14:22:01.725] INFO: running: pixelalive
[14:22:01.735] INFO: ----------------------------------------------------------------------
[14:22:01.735] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:22:01.735] INFO: ----------------------------------------------------------------------
[14:22:02.054] INFO: Expecting 41600 events.
[14:22:06.380] INFO: 41600 events read in total (3608ms).
[14:22:06.549] INFO: Test took 4810ms.
[14:22:06.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:06.820] INFO: PixTestAlive::aliveTest() done
[14:22:06.820] INFO: number of dead pixels (per ROC): 0 0 0 0 7 1 0 0 0 0 0 1 0 0 0 1
[14:22:06.854] INFO: enter test to run
[14:22:51.692] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:22:51.692] INFO: running: highrate
[14:22:51.693] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:22:51.914] INFO: ----------------------------------------------------------------------
[14:22:51.914] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:22:51.914] INFO: ----------------------------------------------------------------------
[14:22:51.914] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:22:51.914] INFO: edge/corner pixel THR is adjusted
[14:22:51.914] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:22:52.874] INFO: Collecting data for 5 seconds...
[14:22:57.891] INFO: Done with hot pixel readout
[14:23:09.864] INFO: PixTest:: pg_setup set to default.
[14:23:09.865] INFO: 8 hot pixels found in step 0
[14:23:10.856] INFO: Collecting data for 5 seconds...
[14:23:15.874] INFO: Done with hot pixel readout
[14:23:27.885] INFO: PixTest:: pg_setup set to default.

[14:23:27.886] INFO: 8 hot pixels found in step 1
[14:23:28.882] INFO: Collecting data for 5 seconds...
[14:23:33.899] INFO: Done with hot pixel readout
[14:23:45.935] INFO: PixTest:: pg_setup set to default.
[14:23:45.935] INFO: 6 hot pixels found in step 2
[14:23:46.931] INFO: Collecting data for 5 seconds...
[14:23:51.947] INFO: Done with hot pixel readout
[14:24:03.938] INFO: PixTest:: pg_setup set to default.
[14:24:03.939] INFO: 6 hot pixels found in step 3
[14:24:04.933] INFO: Collecting data for 5 seconds...
[14:24:09.949] INFO: Done with hot pixel readout
[14:24:21.998] INFO: PixTest:: pg_setup set to default.
[14:24:21.999] INFO: 4 hot pixels found in step 4
[14:24:22.993] INFO: Collecting data for 5 seconds...
[14:24:28.010] INFO: Done with hot pixel readout
[14:24:40.033] INFO: PixTest:: pg_setup set to default.
[14:24:40.034] INFO: 4 hot pixels found in step 5
[14:24:41.029] INFO: Collecting data for 5 seconds...
[14:24:46.046] INFO: Done with hot pixel readout
[14:24:58.048] INFO: PixTest:: pg_setup set to default.
[14:24:58.049] INFO: 4 hot pixels found in step 6
[14:24:59.043] INFO: Collecting data for 5 seconds...
[14:25:04.061] INFO: Done with hot pixel readout
[14:25:16.096] INFO: PixTest:: pg_setup set to default.
[14:25:16.096] INFO: 4 hot pixels found in step 7
[14:25:17.092] INFO: Collecting data for 5 seconds...
[14:25:22.108] INFO: Done with hot pixel readout
[14:25:34.075] INFO: PixTest:: pg_setup set to default.

[14:25:34.076] INFO: 4 hot pixels found in step 8
[14:25:35.071] INFO: Collecting data for 5 seconds...
[14:25:40.087] INFO: Done with hot pixel readout
[14:25:52.117] INFO: PixTest:: pg_setup set to default.
[14:25:52.118] INFO: 4 hot pixels found in step 9
[14:25:53.113] INFO: Collecting data for 5 seconds...
[14:25:58.130] INFO: Done with hot pixel readout
[14:26:10.126] INFO: PixTest:: pg_setup set to default.
[14:26:10.127] INFO: 1 hot pixels found in step 10
[14:26:11.122] INFO: Collecting data for 5 seconds...
[14:26:16.139] INFO: Done with hot pixel readout
[14:26:28.126] INFO: PixTest:: pg_setup set to default.
[14:26:28.127] INFO: 4 hot pixels found in step 11
[14:26:29.121] INFO: Collecting data for 5 seconds...
[14:26:34.138] INFO: Done with hot pixel readout
[14:26:46.138] INFO: PixTest:: pg_setup set to default.
[14:26:46.138] INFO: 2 hot pixels found in step 12
[14:26:47.133] INFO: Collecting data for 5 seconds...
[14:26:52.149] INFO: Done with hot pixel readout
[14:27:04.165] INFO: PixTest:: pg_setup set to default.

[14:27:04.166] INFO: 2 hot pixels found in step 13
[14:27:05.161] INFO: Collecting data for 5 seconds...
[14:27:10.176] INFO: Done with hot pixel readout
[14:27:22.191] INFO: PixTest:: pg_setup set to default.
[14:27:22.191] INFO: 2 hot pixels found in step 14
[14:27:22.230] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:27:22.233] INFO: PixTest::trimHotPixels() done
[14:27:22.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C0.dat
[14:27:22.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C1.dat
[14:27:22.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C2.dat
[14:27:22.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C3.dat
[14:27:22.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C4.dat
[14:27:22.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C5.dat
[14:27:22.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C6.dat
[14:27:22.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C7.dat
[14:27:22.279] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C8.dat
[14:27:22.285] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C9.dat
[14:27:22.290] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C10.dat
[14:27:22.295] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C11.dat
[14:27:22.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C12.dat
[14:27:22.306] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C13.dat
[14:27:22.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C14.dat
[14:27:22.317] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C15.dat
[14:27:22.322] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//defaultMaskFile.dat
[14:27:22.334] INFO: enter test to run
[14:28:44.266] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:28:44.266] INFO: running: highrate
[14:28:44.271] INFO: ----------------------------------------------------------------------
[14:28:44.271] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:28:44.271] INFO: ----------------------------------------------------------------------
[14:28:44.271] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:28:44.271] INFO: edge/corner pixel THR is adjusted
[14:28:44.271] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:28:45.228] INFO: Collecting data for 1 seconds...
[14:28:46.231] INFO: Done with hot pixel readout
[14:28:50.477] INFO: PixTest:: pg_setup set to default.
[14:28:50.477] INFO: 1 hot pixels found in step 0
[14:28:51.520] INFO: Collecting data for 1 seconds...
[14:28:52.523] INFO: Done with hot pixel readout
[14:28:56.771] INFO: PixTest:: pg_setup set to default.
[14:28:56.772] INFO: 1 hot pixels found in step 1
[14:28:57.814] INFO: Collecting data for 1 seconds...
[14:28:58.818] INFO: Done with hot pixel readout
[14:29:03.072] INFO: PixTest:: pg_setup set to default.
[14:29:03.073] INFO: 0 hot pixels found in step 2
[14:29:03.078] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:29:03.162] INFO: PixTest::trimHotPixels() done
[14:29:03.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C0.dat
[14:29:03.174] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C1.dat
[14:29:03.179] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C2.dat
[14:29:03.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C3.dat
[14:29:03.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C4.dat
[14:29:03.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C5.dat
[14:29:03.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C6.dat
[14:29:03.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C7.dat
[14:29:03.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C8.dat
[14:29:03.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C9.dat
[14:29:03.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C10.dat
[14:29:03.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C11.dat
[14:29:03.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C12.dat
[14:29:03.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C13.dat
[14:29:03.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C14.dat
[14:29:03.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//trimParameters35_C15.dat
[14:29:03.252] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-47_FPIXTest-17C-FNAL-160412-1225_2016-04-12_12h25m_1460481943/000_FPIXTest_p17//defaultMaskFile.dat
[14:29:03.262] INFO: enter test to run
[14:30:57.329] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:30:57.329] INFO: running: xray
[14:30:57.330] INFO: ----------------------------------------------------------------------
[14:30:57.330] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:30:57.330] INFO: ----------------------------------------------------------------------
[14:30:58.294] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:31:09.652] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:31:39.029] INFO: Resuming triggers.
[14:31:50.391] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:32:19.780] INFO: Resuming triggers.
[14:32:31.141] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:32:59.963] INFO: Resuming triggers.
[14:33:11.326] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:33:40.587] INFO: Resuming triggers.
[14:33:51.948] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:34:21.373] INFO: Resuming triggers.
[14:34:32.737] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:35:02.096] INFO: Resuming triggers.
[14:35:13.453] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:35:42.792] INFO: Resuming triggers.
[14:35:54.150] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:36:23.498] INFO: Resuming triggers.
[14:36:32.947] INFO: data taking finished, elapsed time: 100 seconds.
[14:36:57.441] INFO: PixTest:: pg_setup set to default.
[14:36:57.444] INFO: PixTestXray::doPhRun() done
[14:36:57.580] INFO: enter test to run
[14:38:00.926] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:38:00.926] INFO: running: xray
[14:38:00.927] INFO: ----------------------------------------------------------------------
[14:38:00.927] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:38:00.927] INFO: ----------------------------------------------------------------------
[14:38:01.913] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:38:08.132] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:38:38.238] INFO: Resuming triggers.
[14:38:44.459] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:39:14.482] INFO: Resuming triggers.
[14:39:20.703] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:39:50.749] INFO: Resuming triggers.
[14:39:56.970] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:40:27.006] INFO: Resuming triggers.
[14:40:33.226] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[14:41:03.247] INFO: Resuming triggers.
[14:41:09.468] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:41:39.505] INFO: Resuming triggers.
[14:41:45.725] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:42:15.677] INFO: Resuming triggers.
[14:42:21.899] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:42:51.939] INFO: Resuming triggers.
[14:42:58.159] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:43:28.158] INFO: Resuming triggers.
[14:43:34.376] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:44:04.446] INFO: Resuming triggers.
[14:44:10.662] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:44:40.663] INFO: Resuming triggers.
[14:44:46.881] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:45:16.911] INFO: Resuming triggers.
[14:45:23.125] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:45:53.118] INFO: Resuming triggers.
[14:45:59.332] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:46:29.341] INFO: Resuming triggers.
[14:46:35.556] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:47:05.541] INFO: Resuming triggers.
[14:47:11.758] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:47:41.674] INFO: Resuming triggers.
[14:47:42.511] INFO: data taking finished, elapsed time: 100 seconds.
[14:47:46.929] INFO: PixTest:: pg_setup set to default.
[14:47:46.932] INFO: PixTestXray::doPhRun() done
[14:47:47.082] INFO: enter test to run
[14:50:04.664] INFO: test: HighRate no parameter change
[14:50:04.664] INFO: running: highrate
[14:50:04.665] INFO: ----------------------------------------------------------------------
[14:50:04.665] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:50:04.666] INFO: ----------------------------------------------------------------------
[14:50:04.805] INFO: Expecting 768 events.
[14:50:05.939] INFO: 768 events read in total (419ms).
[14:50:05.939] INFO: Test took 1267ms.
[14:50:06.743] INFO: Expecting 41600 events.
[14:50:09.862] INFO: 41600 events read in total (2592ms).
[14:50:09.863] INFO: Test took 3915ms.
[14:50:09.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:10.621] INFO: Expecting 41600 events.
[14:50:13.829] INFO: 41600 events read in total (2681ms).
[14:50:13.830] INFO: Test took 3915ms.
[14:50:13.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:14.590] INFO: Expecting 41600 events.
[14:50:17.835] INFO: 41600 events read in total (2718ms).
[14:50:17.836] INFO: Test took 3952ms.
[14:50:17.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:18.590] INFO: Expecting 41600 events.
[14:50:21.834] INFO: 41600 events read in total (2717ms).
[14:50:21.835] INFO: Test took 3945ms.
[14:50:21.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:22.593] INFO: Expecting 41600 events.
[14:50:25.849] INFO: 41600 events read in total (2729ms).
[14:50:25.850] INFO: Test took 3961ms.
[14:50:25.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:26.603] INFO: Expecting 41600 events.
[14:50:29.848] INFO: 41600 events read in total (2718ms).
[14:50:29.849] INFO: Test took 3944ms.
[14:50:29.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:30.605] INFO: Expecting 41600 events.
[14:50:33.855] INFO: 41600 events read in total (2723ms).
[14:50:33.856] INFO: Test took 3952ms.
[14:50:33.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:34.611] INFO: Expecting 41600 events.
[14:50:37.874] INFO: 41600 events read in total (2736ms).
[14:50:37.875] INFO: Test took 3966ms.
[14:50:37.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:38.630] INFO: Expecting 41600 events.
[14:50:41.875] INFO: 41600 events read in total (2719ms).
[14:50:41.876] INFO: Test took 3946ms.
[14:50:41.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:42.634] INFO: Expecting 41600 events.
[14:50:45.890] INFO: 41600 events read in total (2729ms).
[14:50:45.891] INFO: Test took 3962ms.
[14:50:45.926] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:46.645] INFO: Expecting 41600 events.
[14:50:49.911] INFO: 41600 events read in total (2739ms).
[14:50:49.912] INFO: Test took 3967ms.
[14:50:49.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:50.667] INFO: Expecting 41600 events.
[14:50:53.922] INFO: 41600 events read in total (2728ms).
[14:50:53.923] INFO: Test took 3955ms.
[14:50:53.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:54.681] INFO: Expecting 41600 events.
[14:50:57.932] INFO: 41600 events read in total (2724ms).
[14:50:57.933] INFO: Test took 3957ms.
[14:50:57.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:58.692] INFO: Expecting 41600 events.
[14:51:01.950] INFO: 41600 events read in total (2731ms).
[14:51:01.951] INFO: Test took 3966ms.
[14:51:01.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:02.710] INFO: Expecting 41600 events.
[14:51:05.957] INFO: 41600 events read in total (2720ms).
[14:51:05.957] INFO: Test took 3951ms.
[14:51:05.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:06.714] INFO: Expecting 41600 events.
[14:51:09.963] INFO: 41600 events read in total (2722ms).
[14:51:09.964] INFO: Test took 3954ms.
[14:51:09.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:10.719] INFO: Expecting 41600 events.
[14:51:13.972] INFO: 41600 events read in total (2726ms).
[14:51:13.973] INFO: Test took 3954ms.
[14:51:14.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:14.728] INFO: Expecting 41600 events.
[14:51:17.982] INFO: 41600 events read in total (2727ms).
[14:51:17.983] INFO: Test took 3956ms.
[14:51:18.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:18.741] INFO: Expecting 41600 events.
[14:51:21.975] INFO: 41600 events read in total (2707ms).
[14:51:21.976] INFO: Test took 3938ms.
[14:51:22.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:22.732] INFO: Expecting 41600 events.
[14:51:25.803] INFO: 41600 events read in total (2544ms).
[14:51:25.804] INFO: Test took 3774ms.
[14:51:25.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:26.200] INFO: enter test to run
[14:51:37.984] INFO: test: HighRate no parameter change
[14:51:37.984] INFO: running: highrate
[14:51:37.985] INFO: ----------------------------------------------------------------------
[14:51:37.985] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:51:37.985] INFO: ----------------------------------------------------------------------
[14:51:38.601] INFO: Expecting 208000 events.
[14:51:50.536] INFO: 208000 events read in total (11408ms).
[14:51:50.539] INFO: Test took 12545ms.
[14:51:50.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:50.944] INFO: number of dead pixels (per ROC): 0 0 0 0 4 1 0 0 0 0 0 1 0 0 0 1
[14:51:50.944] INFO: number of red-efficiency pixels: 92 64 90 152 177 144 145 119 100 152 117 121 99 78 30 28
[14:51:50.944] INFO: number of X-ray hits detected: 66690 45749 70478 109195 116881 120359 119807 86187 82021 103449 103049 87314 92448 54396 23029 24805
[14:51:50.944] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:51:50.944] INFO: number of Vcal hits detected: 207907 207934 207909 207844 207571 207802 207852 207880 207899 207843 207878 207826 207898 207919 207968 207923
[14:51:50.944] 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 99.9 100.0 100.0 100.0 100.0
[14:51:50.944] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.8 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:51:50.944] INFO: X-ray hit rate [MHz/cm2]: 19.5 13.4 20.7 32.0 34.3 35.3 35.1 25.3 24.0 30.3 30.2 25.6 27.1 15.9 6.7 7.3
[14:51:50.944] INFO: PixTestHighRate::doXPixelAlive() done
[14:51:50.991] INFO: PixTest:: pg_setup set to default.
[14:51:51.007] INFO: enter test to run
[14:52:22.999] INFO: test: HighRate no parameter change
[14:52:22.999] INFO: running: highrate
[14:52:22.001] INFO: ----------------------------------------------------------------------
[14:52:22.001] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:52:22.001] INFO: ----------------------------------------------------------------------
[14:52:23.616] INFO: Expecting 208000 events.
[14:52:37.618] INFO: 208000 events read in total (13475ms).
[14:52:37.623] INFO: Test took 14612ms.
[14:52:37.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:38.255] INFO: number of dead pixels (per ROC): 0 0 0 0 3 1 0 0 0 0 0 1 0 0 0 1
[14:52:38.255] INFO: number of red-efficiency pixels: 231 154 292 599 629 559 469 403 260 503 395 414 331 194 72 77
[14:52:38.255] INFO: number of X-ray hits detected: 147623 100570 155175 242185 257935 264739 264241 190190 182429 226562 228325 192715 203848 119270 51325 55059
[14:52:38.255] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:52:38.255] INFO: number of Vcal hits detected: 207757 207842 207664 207329 207038 207346 207491 207567 207732 207444 207583 207509 207644 207794 207926 207873
[14:52:38.256] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.6 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:52:38.256] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.5 99.7 99.8 99.8 99.9 99.7 99.8 99.8 99.8 99.9 100.0 99.9
[14:52:38.256] INFO: X-ray hit rate [MHz/cm2]: 43.3 29.5 45.5 71.0 75.6 77.6 77.5 55.7 53.5 66.4 66.9 56.5 59.7 35.0 15.0 16.1
[14:52:38.256] INFO: PixTestHighRate::doXPixelAlive() done
[14:52:38.303] INFO: PixTest:: pg_setup set to default.
[14:52:38.315] INFO: enter test to run
[14:52:52.807] INFO: test: HighRate no parameter change
[14:52:52.807] INFO: running: highrate
[14:52:52.808] INFO: ----------------------------------------------------------------------
[14:52:52.808] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:52:52.808] INFO: ----------------------------------------------------------------------
[14:52:53.431] INFO: Expecting 208000 events.
[14:53:09.785] INFO: 208000 events read in total (15828ms).
[14:53:09.793] INFO: Test took 16974ms.
[14:53:10.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:10.664] INFO: number of dead pixels (per ROC): 0 0 0 0 3 1 0 0 0 0 0 1 0 0 0 1
[14:53:10.664] INFO: number of red-efficiency pixels: 509 386 705 1392 1475 1393 1233 994 564 1282 902 955 744 491 143 113
[14:53:10.664] INFO: number of X-ray hits detected: 228339 156481 241537 374514 400178 411294 410142 295796 281390 353479 354540 299880 316089 186496 79942 86200
[14:53:10.664] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:53:10.664] INFO: number of Vcal hits detected: 207380 207561 207041 206082 205704 206125 206434 206680 207361 206310 206919 206744 207139 207426 207855 207835
[14:53:10.664] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.2 99.1 99.2 99.3 99.4 99.7 99.3 99.5 99.5 99.6 99.7 99.9 99.9
[14:53:10.664] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.1 98.9 99.1 99.2 99.4 99.7 99.2 99.5 99.4 99.6 99.7 99.9 99.9
[14:53:10.664] INFO: X-ray hit rate [MHz/cm2]: 66.9 45.9 70.8 109.8 117.3 120.6 120.2 86.7 82.5 103.6 103.9 87.9 92.6 54.7 23.4 25.3
[14:53:10.664] INFO: PixTestHighRate::doXPixelAlive() done
[14:53:10.712] INFO: PixTest:: pg_setup set to default.
[14:53:10.727] INFO: enter test to run
[14:53:20.295] INFO: test: exit no parameter change
[14:53:20.556] QUIET: Connection to board 33 closed.
[14:53:20.557] INFO: pXar: this is the end, my friend