[12:35:59.333] INFO: *** Welcome to pxar ***
[12:35:59.333] INFO: *** Today: 2016/03/10
[12:35:59.375] INFO: *** Version: prod-12-dirty
[12:35:59.375] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//dacParameters35_C15.dat
[12:35:59.417] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:35:59.417] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//defaultMaskFile.dat
[12:35:59.418] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C15.dat
[12:35:59.564] INFO: clk: 4
[12:35:59.564] INFO: ctr: 4
[12:35:59.564] INFO: sda: 19
[12:35:59.564] INFO: tin: 9
[12:35:59.564] INFO: level: 15
[12:35:59.564] INFO: triggerdelay: 0
[12:35:59.564] QUIET: Instanciating API for pxar prod-12
[12:35:59.564] INFO: Log level: INFO
[12:35:59.583] QUIET: Connection to board DTB_WREKRL opened.
[12:35:59.586] 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:
------------------------------------------------------
[12:35:59.589] INFO: RPC call hashes of host and DTB match: 398089610
[12:36:01.123] INFO: DUT info:
[12:36:01.123] INFO: The DUT currently contains the following objects:
[12:36:01.123] INFO: 2 TBM Cores tbm08c (2 ON)
[12:36:01.124] INFO: TBM Core alpha (0): 7 registers set
[12:36:01.124] INFO: TBM Core beta (1): 7 registers set
[12:36:01.124] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:36:01.124] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.124] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:36:01.528] INFO: enter 'restricted' command line mode
[12:36:01.528] INFO: enter test to run
[12:36:15.325] INFO: test: PixelAlive no parameter change
[12:36:15.325] INFO: running: pixelalive
[12:36:15.363] INFO: ----------------------------------------------------------------------
[12:36:15.363] 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:36:15.363] INFO: ----------------------------------------------------------------------
[12:36:15.708] INFO: Expecting 41600 events.
[12:36:20.038] INFO: 41600 events read in total (3612ms).
[12:36:20.200] INFO: Test took 4806ms.
[12:36:20.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:20.492] INFO: PixTestAlive::aliveTest() done
[12:36:20.492] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:36:20.522] INFO: enter test to run
[12:37:01.237] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=50;maskuntrimmable=0<-
[12:37:01.237] INFO: running: highrate
[12:37:01.237] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:37:01.474] INFO: ----------------------------------------------------------------------
[12:37:01.474] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:37:01.474] INFO: ----------------------------------------------------------------------
[12:37:01.474] INFO: THR = 50, corresponding to ~ 26.6667 MHz/cm2
[12:37:01.474] INFO: edge/corner pixel THR is adjusted
[12:37:01.474] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:37:02.433] INFO: Collecting data for 5 seconds...
[12:37:07.444] INFO: Done with hot pixel readout
[12:37:17.674] INFO: PixTest:: pg_setup set to default.
[12:37:17.887] INFO: 26197 hot pixels found in step 0
[12:37:18.882] INFO: Collecting data for 5 seconds...
[12:37:23.896] INFO: Done with hot pixel readout
[12:37:35.899] INFO: PixTest:: pg_setup set to default.
[12:37:36.218] INFO: 25999 hot pixels found in step 1
[12:37:37.215] INFO: Collecting data for 5 seconds...
[12:37:42.232] INFO: Done with hot pixel readout
[12:37:54.183] INFO: PixTest:: pg_setup set to default.
[12:37:54.826] INFO: 25636 hot pixels found in step 2
[12:37:55.824] INFO: Collecting data for 5 seconds...
[12:38:00.840] INFO: Done with hot pixel readout
[12:38:12.743] INFO: PixTest:: pg_setup set to default.
[12:38:13.845] INFO: 25344 hot pixels found in step 3
[12:38:14.842] INFO: Collecting data for 5 seconds...
[12:38:19.859] INFO: Done with hot pixel readout
[12:38:31.717] INFO: PixTest:: pg_setup set to default.
[12:38:33.390] INFO: 24817 hot pixels found in step 4
[12:38:34.389] INFO: Collecting data for 5 seconds...
[12:38:39.406] INFO: Done with hot pixel readout
[12:38:51.185] INFO: PixTest:: pg_setup set to default.
[12:38:53.441] INFO: 24206 hot pixels found in step 5
[12:38:54.440] INFO: Collecting data for 5 seconds...
[12:38:59.457] INFO: Done with hot pixel readout
[12:39:11.188] INFO: PixTest:: pg_setup set to default.
[12:39:13.962] INFO: 23575 hot pixels found in step 6
[12:39:14.960] INFO: Collecting data for 5 seconds...
[12:39:19.976] INFO: Done with hot pixel readout
[12:39:31.662] INFO: PixTest:: pg_setup set to default.
[12:39:34.823] INFO: 22599 hot pixels found in step 7
[12:39:35.823] INFO: Collecting data for 5 seconds...
[12:39:40.839] INFO: Done with hot pixel readout
[12:39:52.440] INFO: PixTest:: pg_setup set to default.
[12:39:55.826] INFO: 21765 hot pixels found in step 8
[12:39:56.827] INFO: Collecting data for 5 seconds...
[12:40:01.844] INFO: Done with hot pixel readout
[12:40:13.439] INFO: PixTest:: pg_setup set to default.
[12:40:16.937] INFO: 21111 hot pixels found in step 9
[12:40:17.933] INFO: Collecting data for 5 seconds...
[12:40:22.950] INFO: Done with hot pixel readout
[12:40:34.509] INFO: PixTest:: pg_setup set to default.
[12:40:38.043] INFO: 20723 hot pixels found in step 10
[12:40:39.040] INFO: Collecting data for 5 seconds...
[12:40:44.056] INFO: Done with hot pixel readout
[12:40:55.583] INFO: PixTest:: pg_setup set to default.
[12:40:59.149] INFO: 20413 hot pixels found in step 11
[12:41:00.145] INFO: Collecting data for 5 seconds...
[12:41:05.161] INFO: Done with hot pixel readout
[12:41:16.702] INFO: PixTest:: pg_setup set to default.
[12:41:20.292] INFO: 20275 hot pixels found in step 12
[12:41:21.290] INFO: Collecting data for 5 seconds...
[12:41:26.307] INFO: Done with hot pixel readout
[12:41:37.797] INFO: PixTest:: pg_setup set to default.
[12:41:41.402] INFO: 20094 hot pixels found in step 13
[12:41:42.399] INFO: Collecting data for 5 seconds...
[12:41:47.415] INFO: Done with hot pixel readout
[12:41:58.002] INFO: PixTest:: pg_setup set to default.
[12:42:02.610] INFO: 19968 hot pixels found in step 14
[12:42:02.708] INFO: PixTest::trimHotPixels() done
[12:42:02.708] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C0.dat
[12:42:02.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C1.dat
[12:42:02.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C2.dat
[12:42:02.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C3.dat
[12:42:02.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C4.dat
[12:42:02.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C5.dat
[12:42:02.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C6.dat
[12:42:02.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C7.dat
[12:42:02.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C8.dat
[12:42:02.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C9.dat
[12:42:02.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C10.dat
[12:42:02.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C11.dat
[12:42:02.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C12.dat
[12:42:02.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C13.dat
[12:42:02.783] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C14.dat
[12:42:02.788] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C15.dat
[12:42:02.810] INFO: enter test to run
[12:42:35.322] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=150;maskuntrimmable=0<-
[12:42:35.323] INFO: running: highrate
[12:42:35.327] INFO: ----------------------------------------------------------------------
[12:42:35.327] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:42:35.327] INFO: ----------------------------------------------------------------------
[12:42:35.327] INFO: THR = 150, corresponding to ~ 400 MHz/cm2
[12:42:35.327] INFO: edge/corner pixel THR is adjusted
[12:42:35.327] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:42:36.285] INFO: Collecting data for 1 seconds...
[12:42:37.288] INFO: Done with hot pixel readout
[12:42:41.343] INFO: PixTest:: pg_setup set to default.
[12:42:41.344] INFO: 0 hot pixels found in step 0
[12:42:41.437] INFO: PixTest::trimHotPixels() done
[12:42:41.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C0.dat
[12:42:41.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C1.dat
[12:42:41.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C2.dat
[12:42:41.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C3.dat
[12:42:41.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C4.dat
[12:42:41.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C5.dat
[12:42:41.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C6.dat
[12:42:41.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C7.dat
[12:42:41.485] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C8.dat
[12:42:41.490] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C9.dat
[12:42:41.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C10.dat
[12:42:41.501] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C11.dat
[12:42:41.506] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C12.dat
[12:42:41.511] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C13.dat
[12:42:41.517] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C14.dat
[12:42:41.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//trimParameters35_C15.dat
[12:42:41.537] INFO: enter test to run
[12:43:03.290] INFO: test: Xray setting parameters: ->savemaskfile=1<-
[12:43:03.290] INFO: running: xray
[12:43:03.296] INFO: ----------------------------------------------------------------------
[12:43:03.296] INFO: PixTest::maskHotPixels() running for 10 seconds with 100 kHz trigger rate
[12:43:03.296] INFO: ----------------------------------------------------------------------
[12:43:04.253] INFO: PixTestHighRate::maskHotPixels start TriggerLoop with period 404 and duration 10 seconds and trigger rate 100 kHz
[12:43:13.296] INFO: Done with hot pixel readout
[12:43:27.468] INFO: PixTest:: pg_setup set to default.
[12:43:27.469] INFO: no hot pixel found!
[12:43:27.469] INFO: PixTest::maskHotPixels() done
[12:43:27.472] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-28_FPIXTest-17C-FNAL-160308-0940_2016-03-08_09h40m_1457451633/000_FPIXTest_p17//defaultMaskFile.dat
[12:43:27.642] INFO: enter test to run
[12:43:59.290] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:43:59.290] INFO: running: xray
[12:43:59.291] INFO: ----------------------------------------------------------------------
[12:43:59.291] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:43:59.291] INFO: ----------------------------------------------------------------------
[12:44:00.254] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:44:12.221] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:44:33.113] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[12:44:33.134] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 has NoTokenPass but 8 ROCs were found
[12:44:33.134] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[12:44:33.134] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:44:33.134] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b7 8040 40e8 40e8 40e8 40e8 40e8 40e8 40e8 40e8 e000 c000
[12:44:33.134] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b1 80c0 40e8 40e8 40e8 40e9 485 2a2d 40e9 40e8 40e9 40e9 e000 c000
[12:44:33.134] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b2 8000 40e8 40e8 40e9 9a 202d 2c9 2a60 30b 2866 40e9 11b 242d 40e8 40e9 40e9 40e9 e000 c000
[12:44:33.134] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b3 8040 40e8 40e9 40e8 40e8 40e8 40e8 341 2443 40e8 40e9 e000 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b4 80b1 40e8 40e8 40e8 40e8 202 2247 40e8 50e8 50e8 50e8 7ea 3aaa afe e0ab c0ea
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b5 80c0 40e8 40e8 40e8 40e8 40e8 40e8 40e8 40e8 e022 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b6 8000 40e8 40e8 40e8 40e8 40e8 40e8 40e8 40e8 e002 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b8 80b1 40e8 40e8 40e8 40e8 40e8 40e8 40e8 40e8 e000 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b2 8000 40e8 40e8 40e9 40e9 40e8 71b 2649 81d 2a4f 40e9 28a 2441 40e9 4cb 224c 40e9 e000 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b3 8040 40e8 40e9 40e8 40e9 40e8 40e8 40e8 40e9 d1 2a2f e000 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b4 80b1 40e8 40e8 d5 284d 40e8 40e8 20b 3289 50e8 50e8 7e0 3000 e001 c040
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b5 80c0 40e8 3f8 40e8 40e8 40e8 40e8 40e8 40e8 e022 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b6 8000 40e8 40e8 40e8 40e8 40e8 40e8 40e8 40e8 e002 c000
[12:44:33.135] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0b7 8040 40e8 40e8 40e8 40e8 40e8 40e8 40e8 40e8 e000 c000
[12:44:41.068] INFO: Resuming triggers.
[12:44:52.883] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:45:19.908] INFO: Resuming triggers.
[12:45:31.726] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:45:59.604] INFO: Resuming triggers.
[12:46:11.425] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:46:40.805] INFO: Resuming triggers.
[12:46:52.627] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:47:20.349] INFO: Resuming triggers.
[12:47:32.174] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:48:01.508] INFO: Resuming triggers.
[12:48:13.331] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:48:42.781] INFO: Resuming triggers.
[12:48:54.602] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:49:24.134] INFO: Resuming triggers.
[12:49:29.733] INFO: data taking finished, elapsed time: 100 seconds.
[12:49:43.998] INFO: PixTest:: pg_setup set to default.
[12:49:43.001] INFO: PixTestXray::doPhRun() done
[12:49:44.137] INFO: enter test to run
[12:49:48.064] INFO: test: HighRate no parameter change
[12:49:48.064] INFO: running: highrate
[12:49:48.065] INFO: ----------------------------------------------------------------------
[12:49:48.065] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:49:48.065] INFO: ----------------------------------------------------------------------
[12:49:48.207] INFO: Expecting 768 events.
[12:49:49.341] INFO: 768 events read in total (419ms).
[12:49:49.341] INFO: Test took 1268ms.
[12:49:50.144] INFO: Expecting 41600 events.
[12:49:53.187] INFO: 41600 events read in total (2516ms).
[12:49:53.188] INFO: Test took 3837ms.
[12:49:53.219] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:53.950] INFO: Expecting 41600 events.
[12:49:57.114] INFO: 41600 events read in total (2637ms).
[12:49:57.115] INFO: Test took 3879ms.
[12:49:57.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:57.874] INFO: Expecting 41600 events.
[12:50:01.076] INFO: 41600 events read in total (2675ms).
[12:50:01.077] INFO: Test took 3914ms.
[12:50:01.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:01.837] INFO: Expecting 41600 events.
[12:50:05.047] INFO: 41600 events read in total (2683ms).
[12:50:05.048] INFO: Test took 3922ms.
[12:50:05.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:05.806] INFO: Expecting 41600 events.
[12:50:09.018] INFO: 41600 events read in total (2685ms).
[12:50:09.019] INFO: Test took 3921ms.
[12:50:09.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:09.776] INFO: Expecting 41600 events.
[12:50:12.993] INFO: 41600 events read in total (2690ms).
[12:50:12.994] INFO: Test took 3925ms.
[12:50:13.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:13.754] INFO: Expecting 41600 events.
[12:50:16.975] INFO: 41600 events read in total (2694ms).
[12:50:16.976] INFO: Test took 3934ms.
[12:50:17.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:17.733] INFO: Expecting 41600 events.
[12:50:20.946] INFO: 41600 events read in total (2686ms).
[12:50:20.947] INFO: Test took 3921ms.
[12:50:20.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:21.705] INFO: Expecting 41600 events.
[12:50:24.935] INFO: 41600 events read in total (2703ms).
[12:50:24.936] INFO: Test took 3941ms.
[12:50:24.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:25.698] INFO: Expecting 41600 events.
[12:50:28.920] INFO: 41600 events read in total (2695ms).
[12:50:28.921] INFO: Test took 3935ms.
[12:50:28.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:29.683] INFO: Expecting 41600 events.
[12:50:32.900] INFO: 41600 events read in total (2691ms).
[12:50:32.901] INFO: Test took 3930ms.
[12:50:32.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:33.663] INFO: Expecting 41600 events.
[12:50:36.897] INFO: 41600 events read in total (2707ms).
[12:50:36.898] INFO: Test took 3949ms.
[12:50:36.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:37.660] INFO: Expecting 41600 events.
[12:50:40.881] INFO: 41600 events read in total (2694ms).
[12:50:40.882] INFO: Test took 3934ms.
[12:50:40.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:41.643] INFO: Expecting 41600 events.
[12:50:44.862] INFO: 41600 events read in total (2692ms).
[12:50:44.863] INFO: Test took 3931ms.
[12:50:44.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:45.621] INFO: Expecting 41600 events.
[12:50:48.848] INFO: 41600 events read in total (2700ms).
[12:50:48.849] INFO: Test took 3936ms.
[12:50:48.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:49.607] INFO: Expecting 41600 events.
[12:50:52.833] INFO: 41600 events read in total (2699ms).
[12:50:52.834] INFO: Test took 3935ms.
[12:50:52.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:53.595] INFO: Expecting 41600 events.
[12:50:56.818] INFO: 41600 events read in total (2697ms).
[12:50:56.819] INFO: Test took 3935ms.
[12:50:56.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:57.580] INFO: Expecting 41600 events.
[12:51:00.800] INFO: 41600 events read in total (2693ms).
[12:51:00.801] INFO: Test took 3933ms.
[12:51:00.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:01.560] INFO: Expecting 41600 events.
[12:51:04.745] INFO: 41600 events read in total (2658ms).
[12:51:04.746] INFO: Test took 3896ms.
[12:51:04.778] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:05.505] INFO: Expecting 41600 events.
[12:51:08.549] INFO: 41600 events read in total (2517ms).
[12:51:08.550] INFO: Test took 3754ms.
[12:51:08.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:08.950] INFO: enter test to run
[12:52:24.599] INFO: test: HighRate no parameter change
[12:52:24.599] INFO: running: highrate
[12:52:24.600] INFO: ----------------------------------------------------------------------
[12:52:24.600] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:52:24.600] INFO: ----------------------------------------------------------------------
[12:52:25.216] INFO: Expecting 208000 events.
[12:52:36.980] INFO: 208000 events read in total (11237ms).
[12:52:36.983] INFO: Test took 12375ms.
[12:52:37.118] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:37.366] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:52:37.366] INFO: number of red-efficiency pixels: 71 43 71 105 111 118 128 89 69 102 122 105 84 63 20 27
[12:52:37.366] INFO: number of X-ray hits detected: 59527 38116 62391 91121 93208 94831 102556 76251 71643 98085 101826 77330 77164 46946 23365 28991
[12:52:37.366] 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:52:37.366] INFO: number of Vcal hits detected: 207928 207957 207928 207893 207887 207877 207870 207909 207931 207897 207875 207895 207916 207937 207980 207972
[12:52:37.366] 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:52:37.366] 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 99.9 100.0 100.0 100.0 100.0
[12:52:37.366] INFO: X-ray hit rate [MHz/cm2]: 17.4 11.2 18.3 26.7 27.3 27.8 30.1 22.3 21.0 28.7 29.8 22.7 22.6 13.8 6.8 8.5
[12:52:37.366] INFO: PixTestHighRate::doXPixelAlive() done
[12:52:37.419] INFO: PixTest:: pg_setup set to default.
[12:52:37.432] INFO: enter test to run
[12:52:57.567] INFO: test: HighRate no parameter change
[12:52:57.567] INFO: running: highrate
[12:52:57.568] INFO: ----------------------------------------------------------------------
[12:52:57.568] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:52:57.568] INFO: ----------------------------------------------------------------------
[12:52:58.182] INFO: Expecting 208000 events.
[12:53:11.409] INFO: 208000 events read in total (12700ms).
[12:53:11.414] INFO: Test took 13838ms.
[12:53:11.681] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:11.971] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:53:11.971] INFO: number of red-efficiency pixels: 186 101 191 265 286 332 423 279 207 296 438 305 205 161 62 53
[12:53:11.971] INFO: number of X-ray hits detected: 120772 77726 126243 184216 189809 192455 208336 155213 144868 198457 206580 156430 157619 95876 48083 58806
[12:53:11.971] 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:53:11.971] INFO: number of Vcal hits detected: 207804 207899 207798 207722 207701 207654 207553 207711 207786 207692 207521 207684 207788 207832 207936 207947
[12:53:11.971] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[12:53:11.971] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.9 99.8 99.8 99.9 99.9 100.0 100.0
[12:53:11.971] INFO: X-ray hit rate [MHz/cm2]: 35.4 22.8 37.0 54.0 55.6 56.4 61.1 45.5 42.5 58.2 60.6 45.9 46.2 28.1 14.1 17.2
[12:53:11.971] INFO: PixTestHighRate::doXPixelAlive() done
[12:53:12.023] INFO: PixTest:: pg_setup set to default.
[12:53:12.039] INFO: enter test to run
[12:54:06.254] INFO: test: HighRate no parameter change
[12:54:06.254] INFO: running: highrate
[12:54:06.255] INFO: ----------------------------------------------------------------------
[12:54:06.255] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:54:06.255] INFO: ----------------------------------------------------------------------
[12:54:06.871] INFO: Expecting 208000 events.
[12:54:21.809] INFO: 208000 events read in total (14411ms).
[12:54:21.817] INFO: Test took 15554ms.
[12:54:22.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:22.634] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:54:22.634] INFO: number of red-efficiency pixels: 475 249 593 695 801 1106 1268 863 523 894 1281 840 690 400 142 148
[12:54:22.634] INFO: number of X-ray hits detected: 210568 135656 222367 321116 328141 334145 363116 271061 255288 347450 361303 273538 273503 168086 83862 103683
[12:54:22.634] 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:54:22.634] INFO: number of Vcal hits detected: 207468 207735 207225 207216 207050 206688 206373 206975 207439 206941 206335 207005 207239 207543 207852 207847
[12:54:22.634] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.4 99.3 99.5 99.7 99.5 99.3 99.6 99.7 99.8 99.9 99.9
[12:54:22.635] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.6 99.5 99.4 99.2 99.5 99.7 99.5 99.2 99.5 99.6 99.8 99.9 99.9
[12:54:22.635] INFO: X-ray hit rate [MHz/cm2]: 61.7 39.8 65.2 94.1 96.2 97.9 106.4 79.4 74.8 101.8 105.9 80.2 80.2 49.3 24.6 30.4
[12:54:22.635] INFO: PixTestHighRate::doXPixelAlive() done
[12:54:22.679] INFO: PixTest:: pg_setup set to default.
[12:54:22.697] INFO: enter test to run
[12:54:25.854] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:54:25.854] INFO: running: xray
[12:54:25.855] INFO: ----------------------------------------------------------------------
[12:54:25.855] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:54:25.855] INFO: ----------------------------------------------------------------------
[12:54:26.820] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:54:33.376] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:55:04.101] INFO: Resuming triggers.
[12:55:10.660] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:55:40.954] INFO: Resuming triggers.
[12:55:47.515] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:56:17.922] INFO: Resuming triggers.
[12:56:24.487] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:56:54.728] INFO: Resuming triggers.
[12:57:01.296] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:57:30.164] INFO: Resuming triggers.
[12:57:36.736] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:58:07.055] INFO: Resuming triggers.
[12:58:13.630] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:58:43.948] INFO: Resuming triggers.
[12:58:50.527] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:59:20.726] INFO: Resuming triggers.
[12:59:27.303] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:59:57.121] INFO: Resuming triggers.
[13:00:03.697] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[13:00:33.990] INFO: Resuming triggers.
[13:00:40.565] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[13:01:10.858] INFO: Resuming triggers.
[13:01:17.428] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:01:47.695] INFO: Resuming triggers.
[13:01:54.263] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:02:24.548] INFO: Resuming triggers.
[13:02:31.113] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:03:01.332] INFO: Resuming triggers.
[13:03:07.893] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:03:38.196] INFO: Resuming triggers.
[13:03:39.001] INFO: data taking finished, elapsed time: 100 seconds.
[13:03:48.692] INFO: PixTest:: pg_setup set to default.
[13:03:48.695] INFO: PixTestXray::doPhRun() done
[13:03:48.845] INFO: enter test to run
[13:03:50.851] INFO: test: exit no parameter change
[13:03:51.208] QUIET: Connection to board 33 closed.
[13:03:51.209] INFO: pXar: this is the end, my friend