[13:16:14.333]     INFO: *** Welcome to pxar ***
[13:16:14.333]     INFO: *** Today: 2016/04/22
[13:16:14.351]     INFO: *** Version: v1.9.0-796-gef167-dirty
[13:16:14.351]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//dacParameters35_C15.dat
[13:16:14.406]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:16:14.406]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//defaultMaskFile.dat
[13:16:14.406]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C15.dat
[13:16:14.507]     INFO:         clk: 4
[13:16:14.507]     INFO:         ctr: 4
[13:16:14.507]     INFO:         sda: 19
[13:16:14.507]     INFO:         tin: 9
[13:16:14.507]     INFO:         level: 15
[13:16:14.507]     INFO:         triggerdelay: 0
[13:16:14.507]    QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:16:14.507]     INFO: Log level: INFO
[13:16:14.526]    QUIET: Connection to board DTB_WREKRL opened.
[13:16:14.529]     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:     
------------------------------------------------------
[13:16:14.532]     INFO: RPC call hashes of host and DTB match: 398089610
[13:16:16.061]     INFO: DUT info: 
[13:16:16.061]     INFO: The DUT currently contains the following objects:
[13:16:16.061]     INFO:  2 TBM Cores tbm08c (2 ON)
[13:16:16.061]     INFO: 	TBM Core alpha (0): 7 registers set
[13:16:16.061]     INFO: 	TBM Core beta  (1): 7 registers set
[13:16:16.061]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:16:16.061]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.062]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:16:16.474]     INFO: enter 'restricted' command line mode
[13:16:16.474]     INFO: enter test to run
[13:16:24.979]     INFO:   test: PixelAlive no parameter change
[13:16:24.980]     INFO:   running: pixelalive
[13:16:24.989]     INFO:    ----------------------------------------------------------------------
[13:16:24.989]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:16:24.989]     INFO:    ----------------------------------------------------------------------
[13:16:25.306]     INFO: Expecting 41600 events.
[13:16:29.635]     INFO: 41600 events read in total (3610ms).
[13:16:29.803]     INFO: Test took 4813ms.
[13:16:29.816]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:30.077]     INFO: PixTestAlive::aliveTest() done
[13:16:30.077]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    1    0    0    0    0    0    0
[13:16:30.110]     INFO: enter test to run
[13:17:06.771]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:17:06.771]     INFO:   running: highrate
[13:17:06.772]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:17:07.121]     INFO:    ----------------------------------------------------------------------
[13:17:07.121]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:17:07.121]     INFO:    ----------------------------------------------------------------------
[13:17:07.121]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:17:07.121]     INFO: edge/corner pixel THR is adjusted
[13:17:07.121]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:17:08.080]     INFO: Collecting data for 5 seconds...
[13:17:13.097]     INFO: Done with hot pixel readout
[13:17:25.062]     INFO: PixTest::       pg_setup set to default.
[13:17:25.063]     INFO: 2 hot pixels found in step 0
[13:17:26.076]     INFO: Collecting data for 5 seconds...
[13:17:31.092]     INFO: Done with hot pixel readout
[13:17:43.027]     INFO: PixTest::       pg_setup set to default.
[13:17:43.028]     INFO: 2 hot pixels found in step 1
[13:17:44.025]     INFO: Collecting data for 5 seconds...
[13:17:49.042]     INFO: Done with hot pixel readout
[13:18:00.998]     INFO: PixTest::       pg_setup set to default.
[13:18:00.999]     INFO: 1 hot pixels found in step 2
[13:18:01.993]     INFO: Collecting data for 5 seconds...
[13:18:07.010]     INFO: Done with hot pixel readout
[13:18:18.956]     INFO: PixTest::       pg_setup set to default.
[13:18:18.957]     INFO: 1 hot pixels found in step 3
[13:18:19.951]     INFO: Collecting data for 5 seconds...
[13:18:24.968]     INFO: Done with hot pixel readout
[13:18:36.859]     INFO: PixTest::       pg_setup set to default.
[13:18:36.860]     INFO: 0 hot pixels found in step 4
[13:18:36.898]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:18:36.901]     INFO: PixTest::trimHotPixels() done
[13:18:36.902]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C0.dat
[13:18:36.907]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C1.dat
[13:18:36.914]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C2.dat
[13:18:36.920]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C3.dat
[13:18:36.925]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C4.dat
[13:18:36.930]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C5.dat
[13:18:36.936]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C6.dat
[13:18:36.941]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C7.dat
[13:18:36.947]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C8.dat
[13:18:36.952]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C9.dat
[13:18:36.957]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C10.dat
[13:18:36.962]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C11.dat
[13:18:36.968]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C12.dat
[13:18:36.973]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C13.dat
[13:18:36.978]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C14.dat
[13:18:36.984]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C15.dat
[13:18:36.989]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//defaultMaskFile.dat
[13:18:36.000]     INFO: enter test to run
[13:19:14.458]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:19:14.458]     INFO:   running: highrate
[13:19:14.462]     INFO:    ----------------------------------------------------------------------
[13:19:14.462]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:19:14.462]     INFO:    ----------------------------------------------------------------------
[13:19:14.462]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:19:14.462]     INFO: edge/corner pixel THR is adjusted
[13:19:14.462]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:19:15.418]     INFO: Collecting data for 1 seconds...
[13:19:16.422]     INFO: Done with hot pixel readout
[13:19:20.497]     INFO: PixTest::       pg_setup set to default.
[13:19:20.498]     INFO: 0 hot pixels found in step 0
[13:19:20.503]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:19:20.592]     INFO: PixTest::trimHotPixels() done
[13:19:20.593]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C0.dat
[13:19:20.600]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C1.dat
[13:19:20.605]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C2.dat
[13:19:20.611]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C3.dat
[13:19:20.616]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C4.dat
[13:19:20.621]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C5.dat
[13:19:20.627]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C6.dat
[13:19:20.632]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C7.dat
[13:19:20.637]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C8.dat
[13:19:20.642]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C9.dat
[13:19:20.647]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C10.dat
[13:19:20.653]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C11.dat
[13:19:20.658]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C12.dat
[13:19:20.663]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C13.dat
[13:19:20.668]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C14.dat
[13:19:20.673]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C15.dat
[13:19:20.679]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-46_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//defaultMaskFile.dat
[13:19:20.688]     INFO: enter test to run
[13:19:50.794]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[13:19:50.794]     INFO:   running: xray
[13:19:50.795]     INFO:    ----------------------------------------------------------------------
[13:19:50.795]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:19:50.795]     INFO:    ----------------------------------------------------------------------
[13:19:51.758]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:20:03.147]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:20:32.438]     INFO: Resuming triggers.
[13:20:43.830]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:21:13.267]     INFO: Resuming triggers.
[13:21:24.657]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:21:54.029]     INFO: Resuming triggers.
[13:22:05.421]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:22:34.797]     INFO: Resuming triggers.
[13:22:46.188]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:23:15.552]     INFO: Resuming triggers.
[13:23:26.942]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:23:56.275]     INFO: Resuming triggers.
[13:24:07.669]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:24:37.080]     INFO: Resuming triggers.
[13:24:48.470]     INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:25:17.831]     INFO: Resuming triggers.
[13:25:27.030]     INFO: data taking finished, elapsed time: 100 seconds.
[13:25:50.871]     INFO: PixTest::       pg_setup set to default.
[13:25:50.875]     INFO: PixTestXray::doPhRun() done
[13:25:51.009]     INFO: enter test to run
[13:26:23.575]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[13:26:23.575]     INFO:   running: xray
[13:26:23.576]     INFO:    ----------------------------------------------------------------------
[13:26:23.576]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:26:23.576]     INFO:    ----------------------------------------------------------------------
[13:26:24.540]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:26:31.095]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:27:01.110]     INFO: Resuming triggers.
[13:27:07.663]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:27:37.700]     INFO: Resuming triggers.
[13:27:44.255]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:28:14.276]     INFO: Resuming triggers.
[13:28:20.833]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:28:50.892]     INFO: Resuming triggers.
[13:28:57.444]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:29:23.600]     INFO: Resuming triggers.
[13:29:30.155]     INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:30:00.101]     INFO: Resuming triggers.
[13:30:06.656]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:30:36.705]     INFO: Resuming triggers.
[13:30:43.258]     INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[13:31:13.107]     INFO: Resuming triggers.
[13:31:19.663]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:31:49.648]     INFO: Resuming triggers.
[13:31:56.205]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[13:32:26.173]     INFO: Resuming triggers.
[13:32:32.730]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:33:02.666]     INFO: Resuming triggers.
[13:33:09.224]     INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:33:39.149]     INFO: Resuming triggers.
[13:33:45.705]     INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:34:15.715]     INFO: Resuming triggers.
[13:34:22.271]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:34:52.276]     INFO: Resuming triggers.
[13:34:58.834]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:35:28.798]     INFO: Resuming triggers.
[13:35:30.788]     INFO: data taking finished, elapsed time: 100 seconds.
[13:35:40.208]     INFO: PixTest::       pg_setup set to default.
[13:35:40.211]     INFO: PixTestXray::doPhRun() done
[13:35:40.360]     INFO: enter test to run
[13:36:08.619]     INFO:   test: HighRate no parameter change
[13:36:08.619]     INFO:   running: highrate
[13:36:08.620]     INFO:    ----------------------------------------------------------------------
[13:36:08.620]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:36:08.620]     INFO:    ----------------------------------------------------------------------
[13:36:08.760]     INFO: Expecting 768 events.
[13:36:09.894]     INFO: 768 events read in total (418ms).
[13:36:09.894]     INFO: Test took 1268ms.
[13:36:10.697]     INFO: Expecting 41600 events.
[13:36:13.834]     INFO: 41600 events read in total (2610ms).
[13:36:13.835]     INFO: Test took 3933ms.
[13:36:13.869]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:14.589]     INFO: Expecting 41600 events.
[13:36:17.791]     INFO: 41600 events read in total (2675ms).
[13:36:17.792]     INFO: Test took 3904ms.
[13:36:17.827]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:18.552]     INFO: Expecting 41600 events.
[13:36:21.799]     INFO: 41600 events read in total (2720ms).
[13:36:21.800]     INFO: Test took 3954ms.
[13:36:21.836]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:22.558]     INFO: Expecting 41600 events.
[13:36:25.802]     INFO: 41600 events read in total (2717ms).
[13:36:25.803]     INFO: Test took 3949ms.
[13:36:25.838]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:26.558]     INFO: Expecting 41600 events.
[13:36:29.823]     INFO: 41600 events read in total (2738ms).
[13:36:29.824]     INFO: Test took 3968ms.
[13:36:29.859]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:30.578]     INFO: Expecting 41600 events.
[13:36:33.822]     INFO: 41600 events read in total (2717ms).
[13:36:33.823]     INFO: Test took 3945ms.
[13:36:33.858]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:34.581]     INFO: Expecting 41600 events.
[13:36:37.839]     INFO: 41600 events read in total (2731ms).
[13:36:37.840]     INFO: Test took 3965ms.
[13:36:37.874]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:38.593]     INFO: Expecting 41600 events.
[13:36:41.839]     INFO: 41600 events read in total (2719ms).
[13:36:41.840]     INFO: Test took 3948ms.
[13:36:41.875]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:42.600]     INFO: Expecting 41600 events.
[13:36:45.866]     INFO: 41600 events read in total (2739ms).
[13:36:45.867]     INFO: Test took 3974ms.
[13:36:45.903]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:46.621]     INFO: Expecting 41600 events.
[13:36:49.866]     INFO: 41600 events read in total (2718ms).
[13:36:49.867]     INFO: Test took 3945ms.
[13:36:49.902]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:50.625]     INFO: Expecting 41600 events.
[13:36:53.861]     INFO: 41600 events read in total (2709ms).
[13:36:53.862]     INFO: Test took 3942ms.
[13:36:53.897]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:54.620]     INFO: Expecting 41600 events.
[13:36:57.872]     INFO: 41600 events read in total (2726ms).
[13:36:57.873]     INFO: Test took 3957ms.
[13:36:57.907]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:58.632]     INFO: Expecting 41600 events.
[13:37:01.888]     INFO: 41600 events read in total (2729ms).
[13:37:01.889]     INFO: Test took 3963ms.
[13:37:01.924]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:02.646]     INFO: Expecting 41600 events.
[13:37:05.888]     INFO: 41600 events read in total (2715ms).
[13:37:05.889]     INFO: Test took 3945ms.
[13:37:05.924]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:06.648]     INFO: Expecting 41600 events.
[13:37:09.907]     INFO: 41600 events read in total (2732ms).
[13:37:09.908]     INFO: Test took 3965ms.
[13:37:09.943]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:10.666]     INFO: Expecting 41600 events.
[13:37:13.922]     INFO: 41600 events read in total (2729ms).
[13:37:13.923]     INFO: Test took 3961ms.
[13:37:13.958]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:14.677]     INFO: Expecting 41600 events.
[13:37:17.931]     INFO: 41600 events read in total (2727ms).
[13:37:17.932]     INFO: Test took 3955ms.
[13:37:17.968]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:18.687]     INFO: Expecting 41600 events.
[13:37:21.953]     INFO: 41600 events read in total (2739ms).
[13:37:21.954]     INFO: Test took 3967ms.
[13:37:21.989]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:22.711]     INFO: Expecting 41600 events.
[13:37:25.923]     INFO: 41600 events read in total (2685ms).
[13:37:25.924]     INFO: Test took 3916ms.
[13:37:25.958]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:26.679]     INFO: Expecting 41600 events.
[13:37:29.797]     INFO: 41600 events read in total (2591ms).
[13:37:29.798]     INFO: Test took 3820ms.
[13:37:29.832]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:30.194]     INFO: enter test to run
[13:37:34.850]     INFO:   test: HighRate no parameter change
[13:37:34.850]     INFO:   running: highrate
[13:37:34.851]     INFO:    ----------------------------------------------------------------------
[13:37:34.851]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:37:34.851]     INFO:    ----------------------------------------------------------------------
[13:37:35.462]     INFO: Expecting 208000 events.
[13:37:47.364]     INFO: 208000 events read in total (11375ms).
[13:37:47.368]     INFO: Test took 12509ms.
[13:37:47.516]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:47.769]     INFO: number of dead pixels (per ROC):     0    0    0    0    0   27    0    0    0    1    0    0    0    0    0    0
[13:37:47.769]     INFO: number of red-efficiency pixels:    86   44   82  118  138  294  119   95   70  111  121   96   76   58   29   31
[13:37:47.769]     INFO: number of X-ray hits detected:    57598 43791 67802 110612 118443 147099 117193 84589 81466 98021 96850 83210 83578 49486 21671 24420
[13:37:47.769]     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:37:47.769]     INFO: number of Vcal hits detected:  207912 207955 207917 207878 207860 204501 207879 207905 207927 207838 207877 207902 207923 207941 207971 207968
[13:37:47.769]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 98.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:37:47.769]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 98.3 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:37:47.769]     INFO: X-ray hit rate [MHz/cm2]:  16.9 12.8 19.9 32.4 34.7 43.1 34.4 24.8 23.9 28.7 28.4 24.4 24.5 14.5 6.4 7.2
[13:37:47.769]     INFO: PixTestHighRate::doXPixelAlive() done
[13:37:47.817]     INFO: PixTest::       pg_setup set to default.
[13:37:47.829]     INFO: enter test to run
[13:38:09.954]     INFO:   test: HighRate no parameter change
[13:38:09.954]     INFO:   running: highrate
[13:38:09.955]     INFO:    ----------------------------------------------------------------------
[13:38:09.955]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:38:09.955]     INFO:    ----------------------------------------------------------------------
[13:38:10.572]     INFO: Expecting 208000 events.
[13:38:24.321]     INFO: 208000 events read in total (13222ms).
[13:38:24.326]     INFO: Test took 14362ms.
[13:38:24.626]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:24.929]     INFO: number of dead pixels (per ROC):     0    0    0    0    0   17    0    0    0    1    0    0    0    0    0    0
[13:38:24.929]     INFO: number of red-efficiency pixels:   210  107  317  376  431  630  616  374  226  416  299  269  282  130   59   66
[13:38:24.929]     INFO: number of X-ray hits detected:    121655 93259 142188 235532 249001 282921 246734 180056 174976 206101 205114 177129 177005 104195 46144 52458
[13:38:24.929]     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:38:24.929]     INFO: number of Vcal hits detected:  207773 207891 207652 207604 207525 203886 207312 207586 207765 207505 207680 207718 207709 207868 207937 207933
[13:38:24.929]     INFO: Vcal hit fiducial efficiency (%):  99.9 100.0 99.8 99.8 99.8 98.4 99.7 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[13:38:24.929]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.8 99.8 98.0 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:38:24.929]     INFO: X-ray hit rate [MHz/cm2]:  35.7 27.3 41.7 69.0 73.0 82.9 72.3 52.8 51.3 60.4 60.1 51.9 51.9 30.5 13.5 15.4
[13:38:24.929]     INFO: PixTestHighRate::doXPixelAlive() done
[13:38:24.975]     INFO: PixTest::       pg_setup set to default.
[13:38:24.992]     INFO: enter test to run
[13:38:45.410]     INFO:   test: HighRate no parameter change
[13:38:45.410]     INFO:   running: highrate
[13:38:45.411]     INFO:    ----------------------------------------------------------------------
[13:38:45.411]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:38:45.411]     INFO:    ----------------------------------------------------------------------
[13:38:46.023]     INFO: Expecting 208000 events.
[13:39:01.775]     INFO: 208000 events read in total (15226ms).
[13:39:01.783]     INFO: Test took 16364ms.
[13:39:02.251]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:02.605]     INFO: number of dead pixels (per ROC):     0    0    0    0    0   12    0    0    0    1    0    0    0    0    0    0
[13:39:02.605]     INFO: number of red-efficiency pixels:   444  217  697  945 1093 1310 1341  806  521  989  696  555  554  301  101   91
[13:39:02.605]     INFO: number of X-ray hits detected:    185079 141164 217858 356229 379796 416611 374862 273059 264448 313560 312312 268283 267761 158066 69777 80283
[13:39:02.605]     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:39:02.605]     INFO: number of Vcal hits detected:  207483 207771 207067 206858 206624 202769 206191 207007 207423 206748 207211 207357 207378 207659 207892 207907
[13:39:02.605]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.6 99.5 99.4 97.8 99.2 99.6 99.8 99.5 99.7 99.7 99.7 99.8 100.0 100.0
[13:39:02.605]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.6 99.5 99.3 97.5 99.1 99.5 99.7 99.4 99.6 99.7 99.7 99.8 99.9 100.0
[13:39:02.605]     INFO: X-ray hit rate [MHz/cm2]:  54.2 41.4 63.9 104.4 111.3 122.1 109.9 80.0 77.5 91.9 91.5 78.6 78.5 46.3 20.5 23.5
[13:39:02.605]     INFO: PixTestHighRate::doXPixelAlive() done
[13:39:02.650]     INFO: PixTest::       pg_setup set to default.
[13:39:02.664]     INFO: enter test to run
[13:39:05.850]     INFO:   test: exit no parameter change
[13:39:06.211]    QUIET: Connection to board 33 closed.
[13:39:06.212]     INFO: pXar: this is the end, my friend