Test Date: 2015-09-09 14:03
Analysis date: 2015-11-23 17:24
Logfile
pxar.log
[13:09:17.026] INFO: *** Welcome to pxar ***
[13:09:17.026] INFO: *** Today: 2015/09/09
[13:09:17.026] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[13:09:17.028] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[13:09:17.029] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[13:09:17.029] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[13:09:17.111] INFO: clk: 4
[13:09:17.111] INFO: ctr: 4
[13:09:17.111] INFO: sda: 19
[13:09:17.111] INFO: tin: 9
[13:09:17.111] INFO: level: 15
[13:09:17.111] INFO: triggerdelay: 0
[13:09:17.111] QUIET: Instanciating API for pxar 2.5
[13:09:17.111] INFO: Log level: INFO
[13:09:17.120] INFO: Found DTB DTB_WZ4QKL
[13:09:17.135] QUIET: Connection to board DTB_WZ4QKL opened.
[13:09:17.139] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[13:09:17.142] INFO: RPC call hashes of host and DTB match: 397073690
[13:09:18.979] INFO: DUT info:
[13:09:18.979] INFO: The DUT currently contains the following objects:
[13:09:18.979] INFO: 2 TBM Cores tbm08c (2 ON)
[13:09:18.979] INFO: TBM Core alpha (0): 7 registers set
[13:09:18.979] INFO: TBM Core beta (1): 7 registers set
[13:09:18.979] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:09:18.979] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.979] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.979] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:18.980] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:09:19.392] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[13:09:19.620] INFO: ######################################################################
[13:09:19.621] INFO: PixTestXray::doTest()
[13:09:19.621] INFO: ######################################################################
[13:09:19.621] INFO: ----------------------------------------------------------------------
[13:09:19.621] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:09:19.621] INFO: ----------------------------------------------------------------------
[13:09:20.642] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:09:24.535] INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[13:09:32.189] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 5 ROCs were found

[13:09:32.190] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:09:32.190] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (183) != TBM ID (6)

[13:09:32.190] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (2) != Token Chain Length (8)

[13:09:32.190] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (7) != TBM ID (49)

[13:09:32.190] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:09:32.190] WARNING: Channel 0 ROC 0: Readback start marker after 17 readouts!

[13:09:32.190] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:09:32.190] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:09:32.190] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:09:36.858] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 8 ROCs were found

[13:09:36.859] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (7) != Token Chain Length (8)

[13:09:38.057] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[13:09:38.058] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (4) != Token Chain Length (8)

[13:09:38.058] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:09:38.058] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:09:38.058] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:09:38.058] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:09:38.058] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:09:38.058] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:09:42.720] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:09:42.721] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 8 ROCs were found

[13:09:42.721] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:09:48.506] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 8 ROCs were found

[13:09:48.507] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 8 ROCs were found

[13:09:49.732] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:09:49.732] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:09:54.484] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:09:54.484] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:09:54.489] WARNING: Channel 1 ROC 4: Readback start marker after 32 readouts!

[13:09:55.837] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[13:09:55.837] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (2) != Token Chain Length (8)

[13:09:55.837] WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:09:55.837] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:10:06.480] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[13:10:06.481] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 7 ROCs were found

[13:10:06.481] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:10:06.481] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:10:06.481] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:10:07.678] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:10:07.678] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (4) != Token Chain Length (8)

[13:10:07.678] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:10:07.678] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:10:07.678] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:10:07.678] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:10:25.379] INFO: Resuming triggers.
[13:10:29.280] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:11:29.449] INFO: Resuming triggers.
[13:11:33.365] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:12:34.339] INFO: Resuming triggers.
[13:12:38.263] INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[13:12:39.323] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[13:12:39.323] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[13:12:39.323] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:12:39.323] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:12:39.323] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:12:39.323] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:12:48.877] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 8 ROCs were found

[13:12:57.172] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 2 ROCs were found

[13:12:57.173] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:12:57.173] WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!

[13:12:57.173] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:12:57.173] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:12:57.173] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:12:57.173] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:12:57.173] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:12:57.173] WARNING: Channel 0 ROC 4: Readback start marker after 15 readouts!

[13:13:38.178] INFO: Resuming triggers.
[13:13:42.080] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:14:07.164] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 1 ROCs were found

[13:14:07.164] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 1 ROCs were found

[13:14:07.164] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (150) != TBM ID (85)

[13:14:07.164] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (3) != Token Chain Length (8)

[13:14:07.165] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (86) != TBM ID (150)

[13:14:07.165] WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 1 ROC 0: Readback start marker after 17 readouts!

[13:14:07.165] WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:14:07.165] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:14:41.385] INFO: Resuming triggers.
[13:14:45.292] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:15:42.634] INFO: Resuming triggers.
[13:15:46.537] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:16:24.942] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 1 ROCs were found

[13:16:24.942] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:16:24.942] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (67) != TBM ID (136)

[13:16:24.943] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[13:16:24.943] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (137) != TBM ID (67)

[13:16:24.943] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:16:24.943] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:16:24.943] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:16:44.502] INFO: Resuming triggers.
[13:16:48.407] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:16:49.771] WARNING: Channel 0 ROC 3: Readback start marker after 4 readouts!

[13:16:49.771] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[13:16:49.772] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 6 ROCs were found

[13:16:49.772] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:16:49.772] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:16:49.772] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:16:50.976] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[13:16:50.976] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:16:50.976] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:17:45.275] INFO: Resuming triggers.
[13:17:49.186] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:18:46.781] INFO: Resuming triggers.
[13:18:50.692] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:18:50.861] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 8 ROCs were found

[13:19:47.541] INFO: Resuming triggers.
[13:19:51.446] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:20:47.451] INFO: Resuming triggers.
[13:20:51.357] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:21:46.822] INFO: Resuming triggers.
[13:21:50.741] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:22:45.808] INFO: Resuming triggers.
[13:22:49.721] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:23:03.408] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (7) != Token Chain Length (8)

[13:23:03.408] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (5) != Token Chain Length (8)

[13:23:03.408] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:23:03.408] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:23:04.583] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (81) != TBM ID (82)

[13:23:04.584] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (81) != TBM ID (82)

[13:23:04.584] WARNING: Channel 0 ROC 4: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:23:04.584] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:23:04.585] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:23:44.364] INFO: Resuming triggers.
[13:23:48.268] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:23:48.534] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:23:48.534] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:24:42.313] INFO: Resuming triggers.
[13:24:46.216] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[13:25:39.571] INFO: Resuming triggers.
[13:25:43.474] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:26:37.290] INFO: Resuming triggers.
[13:26:41.217] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:26:42.253] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 3 ROCs were found

[13:26:42.253] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[13:26:42.253] WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!

[13:26:42.253] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[13:26:42.253] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:26:42.253] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:26:42.253] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:27:35.166] INFO: Resuming triggers.
[13:27:39.070] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:28:31.999] INFO: Resuming triggers.
[13:28:35.904] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:29:28.883] INFO: Resuming triggers.
[13:29:32.786] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:30:25.898] INFO: Resuming triggers.
[13:30:29.807] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:31:23.207] INFO: Resuming triggers.
[13:31:27.111] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:31:27.529] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (7) != Token Chain Length (8)

[13:31:27.530] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 6 ROCs were found

[13:31:27.530] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:32:19.654] INFO: Resuming triggers.
[13:32:23.565] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:33:15.735] INFO: Resuming triggers.
[13:33:19.645] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[13:33:19.858] WARNING: Channel 0 ROC 3: Readback start marker after 3 readouts!

[13:33:19.859] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[13:33:19.859] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (7) != Token Chain Length (8)

[13:33:19.859] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[13:33:19.859] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:34:12.499] INFO: Resuming triggers.
[13:34:15.060] INFO: data taking finished, elapsed time: 100 seconds.
[13:34:16.409] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 6 ROCs were found

[13:34:16.409] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[13:34:16.409] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[13:34:16.409] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[13:34:16.409] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[13:34:16.409] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[13:34:52.634] INFO: PixTest:: pg_setup set to default.
[13:34:52.636] INFO: PixTestXray::doPhRun() done
[13:34:52.636] INFO: PixTestXray::doTest() done
[13:34:53.047] QUIET: Connection to board 172 closed.
[13:34:53.070] INFO: pXar: this is the end, my friend
pxar.log
[13:36:21.095] INFO: *** Welcome to pxar ***
[13:36:21.095] INFO: *** Today: 2015/09/09
[13:36:21.095] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[13:36:21.096] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[13:36:21.096] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[13:36:21.096] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[13:36:21.175] INFO: clk: 4
[13:36:21.175] INFO: ctr: 4
[13:36:21.176] INFO: sda: 19
[13:36:21.176] INFO: tin: 9
[13:36:21.176] INFO: level: 15
[13:36:21.176] INFO: triggerdelay: 0
[13:36:21.176] QUIET: Instanciating API for pxar 2.5
[13:36:21.176] INFO: Log level: INFO
[13:36:21.187] INFO: Found DTB DTB_WZ4QKL
[13:36:21.199] QUIET: Connection to board DTB_WZ4QKL opened.
[13:36:21.202] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[13:36:21.206] INFO: RPC call hashes of host and DTB match: 397073690
[13:36:23.032] INFO: DUT info:
[13:36:23.032] INFO: The DUT currently contains the following objects:
[13:36:23.032] INFO: 2 TBM Cores tbm08c (2 ON)
[13:36:23.032] INFO: TBM Core alpha (0): 7 registers set
[13:36:23.032] INFO: TBM Core beta (1): 7 registers set
[13:36:23.032] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:36:23.032] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.032] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.032] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.033] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:23.444] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[13:36:23.673] INFO: ######################################################################
[13:36:23.673] INFO: PixTestXray::doTest()
[13:36:23.673] INFO: ######################################################################
[13:36:23.673] INFO: ----------------------------------------------------------------------
[13:36:23.673] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:36:23.673] INFO: ----------------------------------------------------------------------
[13:36:24.685] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:36:32.667] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:37:28.297] INFO: Resuming triggers.
[13:37:36.285] INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[13:38:31.949] INFO: Resuming triggers.
[13:38:39.942] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:39:35.616] INFO: Resuming triggers.
[13:39:43.599] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:40:38.643] INFO: Resuming triggers.
[13:40:46.627] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:41:40.919] INFO: Resuming triggers.
[13:41:48.911] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:42:42.569] INFO: Resuming triggers.
[13:42:50.549] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:43:43.151] INFO: Resuming triggers.
[13:43:51.142] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:44:42.823] INFO: Resuming triggers.
[13:44:50.802] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:45:41.785] INFO: Resuming triggers.
[13:45:49.763] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:46:39.680] INFO: Resuming triggers.
[13:46:47.660] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:47:36.962] INFO: Resuming triggers.
[13:47:44.950] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[13:48:33.824] INFO: Resuming triggers.
[13:48:38.277] INFO: data taking finished, elapsed time: 100 seconds.
[13:49:04.599] INFO: PixTest:: pg_setup set to default.
[13:49:04.601] INFO: PixTestXray::doPhRun() done
[13:49:04.601] INFO: PixTestXray::doTest() done
[13:49:04.998] QUIET: Connection to board 172 closed.
[13:49:05.021] INFO: pXar: this is the end, my friend
pxar.log
[13:50:08.475] INFO: *** Welcome to pxar ***
[13:50:08.475] INFO: *** Today: 2015/09/09
[13:50:08.475] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[13:50:08.476] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[13:50:08.476] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[13:50:08.476] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[13:50:08.554] INFO: clk: 4
[13:50:08.554] INFO: ctr: 4
[13:50:08.554] INFO: sda: 19
[13:50:08.554] INFO: tin: 9
[13:50:08.554] INFO: level: 15
[13:50:08.554] INFO: triggerdelay: 0
[13:50:08.554] QUIET: Instanciating API for pxar 2.5
[13:50:08.554] INFO: Log level: INFO
[13:50:08.563] INFO: Found DTB DTB_WZ4QKL
[13:50:08.578] QUIET: Connection to board DTB_WZ4QKL opened.
[13:50:08.582] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[13:50:08.586] INFO: RPC call hashes of host and DTB match: 397073690
[13:50:10.397] INFO: DUT info:
[13:50:10.398] INFO: The DUT currently contains the following objects:
[13:50:10.398] INFO: 2 TBM Cores tbm08c (2 ON)
[13:50:10.398] INFO: TBM Core alpha (0): 7 registers set
[13:50:10.398] INFO: TBM Core beta (1): 7 registers set
[13:50:10.398] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:50:10.398] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.398] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.399] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:10.801] INFO: enter 'restricted' command line mode
[13:50:10.801] INFO: enter test to run
[13:50:10.801] INFO: test: highrate no parameter change
[13:50:10.801] INFO: running: highrate
[13:50:10.809] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[13:50:11.025] INFO: ----------------------------------------------------------------------
[13:50:11.025] INFO: PixTestHighRate::xNoiseMaps() ntrig = 25, vcal = 200
[13:50:11.025] INFO: ----------------------------------------------------------------------
[13:50:11.033] INFO: ---> dac: vcal name: xNoiseMap ntrig: 25 dacrange: 0 .. 100 (1/-1) hits flags = 384 (plus default)
[13:50:11.072] INFO: dacScan step from 0 .. 0
[13:50:11.072] INFO: dacScan split into 1 runs with ntrig = 25
[13:50:11.072] INFO: run 1 of 1
[13:50:11.919] INFO: Expecting 104000 events.
[13:50:24.368] INFO: 104000 events read in total (11918ms).
[13:50:24.385] INFO: Test took 13313ms.
[13:50:24.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:24.770] INFO: dacScan step from 1 .. 1
[13:50:24.770] INFO: dacScan split into 1 runs with ntrig = 25
[13:50:24.770] INFO: run 1 of 1
[13:50:25.615] INFO: Expecting 104000 events.
[13:50:37.938] INFO: 104000 events read in total (11796ms).
[13:50:37.948] INFO: Test took 13177ms.
[13:50:38.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:38.347] INFO: dacScan step from 2 .. 2
[13:50:38.347] INFO: dacScan split into 1 runs with ntrig = 25
[13:50:38.348] INFO: run 1 of 1
[13:50:39.189] INFO: Expecting 104000 events.
[13:50:51.405] INFO: 104000 events read in total (11689ms).
[13:50:51.414] INFO: Test took 13066ms.
[13:50:51.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:51.822] INFO: dacScan step from 3 .. 3
[13:50:51.822] INFO: dacScan split into 1 runs with ntrig = 25
[13:50:51.822] INFO: run 1 of 1
[13:50:52.676] INFO: Expecting 104000 events.
[13:51:04.859] INFO: 104000 events read in total (11656ms).
[13:51:04.869] INFO: Test took 13047ms.
[13:51:04.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:05.263] INFO: dacScan step from 4 .. 4
[13:51:05.263] INFO: dacScan split into 1 runs with ntrig = 25
[13:51:05.263] INFO: run 1 of 1
[13:51:06.112] INFO: Expecting 104000 events.
[13:51:17.978] INFO: 104000 events read in total (11339ms).
[13:51:17.988] INFO: Test took 12725ms.
[13:51:18.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:18.376] INFO: dacScan step from 5 .. 5
[13:51:18.377] INFO: dacScan split into 1 runs with ntrig = 25
[13:51:18.377] INFO: run 1 of 1
[13:51:19.226] INFO: Expecting 104000 events.
[13:51:30.844] INFO: 104000 events read in total (11091ms).
[13:51:30.854] INFO: Test took 12477ms.
[13:51:30.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:31.248] INFO: dacScan step from 6 .. 6
[13:51:31.248] INFO: dacScan split into 1 runs with ntrig = 25
[13:51:31.248] INFO: run 1 of 1
[13:51:32.097] INFO: Expecting 104000 events.
[13:51:43.530] INFO: 104000 events read in total (10906ms).
[13:51:43.540] INFO: Test took 12292ms.
[13:51:43.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:43.942] INFO: dacScan step from 7 .. 7
[13:51:43.942] INFO: dacScan split into 1 runs with ntrig = 25
[13:51:43.942] INFO: run 1 of 1
[13:51:44.790] INFO: Expecting 104000 events.
[13:51:56.515] INFO: 104000 events read in total (11198ms).
[13:51:56.531] INFO: Test took 12589ms.
[13:51:56.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:56.938] INFO: dacScan step from 8 .. 8
[13:51:56.938] INFO: dacScan split into 1 runs with ntrig = 25
[13:51:56.939] INFO: run 1 of 1
[13:51:57.785] INFO: Expecting 104000 events.
[13:52:09.498] INFO: 104000 events read in total (11186ms).
[13:52:09.509] INFO: Test took 12570ms.
[13:52:09.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:09.899] INFO: dacScan step from 9 .. 9
[13:52:09.899] INFO: dacScan split into 1 runs with ntrig = 25
[13:52:09.899] INFO: run 1 of 1
[13:52:10.749] INFO: Expecting 104000 events.
[13:52:22.212] INFO: 104000 events read in total (10936ms).
[13:52:22.222] INFO: Test took 12322ms.
[13:52:22.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:22.612] INFO: dacScan step from 10 .. 10
[13:52:22.612] INFO: dacScan split into 1 runs with ntrig = 25
[13:52:22.612] INFO: run 1 of 1
[13:52:23.463] INFO: Expecting 104000 events.
[13:52:35.354] INFO: 104000 events read in total (11364ms).
[13:52:35.366] INFO: Test took 12753ms.
[13:52:35.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:35.763] INFO: dacScan step from 11 .. 11
[13:52:35.763] INFO: dacScan split into 1 runs with ntrig = 25
[13:52:35.763] INFO: run 1 of 1
[13:52:36.616] INFO: Expecting 104000 events.
[13:52:48.535] INFO: 104000 events read in total (11392ms).
[13:52:48.546] INFO: Test took 12783ms.
[13:52:48.640] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:48.936] INFO: dacScan step from 12 .. 12
[13:52:48.936] INFO: dacScan split into 1 runs with ntrig = 25
[13:52:48.936] INFO: run 1 of 1
[13:52:49.786] INFO: Expecting 104000 events.
[13:53:01.612] INFO: 104000 events read in total (11298ms).
[13:53:01.624] INFO: Test took 12687ms.
[13:53:01.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:02.017] INFO: dacScan step from 13 .. 13
[13:53:02.017] INFO: dacScan split into 1 runs with ntrig = 25
[13:53:02.017] INFO: run 1 of 1
[13:53:02.865] INFO: Expecting 104000 events.
[13:53:14.730] INFO: 104000 events read in total (11338ms).
[13:53:14.740] INFO: Test took 12723ms.
[13:53:14.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:15.134] INFO: dacScan step from 14 .. 14
[13:53:15.134] INFO: dacScan split into 1 runs with ntrig = 25
[13:53:15.134] INFO: run 1 of 1
[13:53:15.981] INFO: Expecting 104000 events.
[13:53:27.897] INFO: 104000 events read in total (11389ms).
[13:53:27.907] INFO: Test took 12772ms.
[13:53:27.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:28.280] INFO: dacScan step from 15 .. 15
[13:53:28.280] INFO: dacScan split into 1 runs with ntrig = 25
[13:53:28.280] INFO: run 1 of 1
[13:53:29.125] INFO: Expecting 104000 events.
[13:53:41.396] INFO: 104000 events read in total (11744ms).
[13:53:41.407] INFO: Test took 13126ms.
[13:53:41.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:41.783] INFO: dacScan step from 16 .. 16
[13:53:41.783] INFO: dacScan split into 1 runs with ntrig = 25
[13:53:41.783] INFO: run 1 of 1
[13:53:42.610] INFO: Expecting 104000 events.
[13:53:54.802] INFO: 104000 events read in total (11664ms).
[13:53:54.811] INFO: Test took 13027ms.
[13:53:54.901] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:55.184] INFO: dacScan step from 17 .. 17
[13:53:55.184] INFO: dacScan split into 1 runs with ntrig = 25
[13:53:55.184] INFO: run 1 of 1
[13:53:56.019] INFO: Expecting 104000 events.
[13:54:08.400] INFO: 104000 events read in total (11854ms).
[13:54:08.409] INFO: Test took 13224ms.
[13:54:08.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:08.784] INFO: dacScan step from 18 .. 18
[13:54:08.784] INFO: dacScan split into 1 runs with ntrig = 25
[13:54:08.784] INFO: run 1 of 1
[13:54:09.609] INFO: Expecting 104000 events.
[13:54:22.393] INFO: 104000 events read in total (12257ms).
[13:54:22.403] INFO: Test took 13618ms.
[13:54:22.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:22.785] INFO: dacScan step from 19 .. 19
[13:54:22.785] INFO: dacScan split into 1 runs with ntrig = 25
[13:54:22.785] INFO: run 1 of 1
[13:54:23.615] INFO: Expecting 104000 events.
[13:54:36.552] INFO: 104000 events read in total (12410ms).
[13:54:36.562] INFO: Test took 13776ms.
[13:54:36.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:36.951] INFO: dacScan step from 20 .. 20
[13:54:36.951] INFO: dacScan split into 1 runs with ntrig = 25
[13:54:36.951] INFO: run 1 of 1
[13:54:37.797] INFO: Expecting 104000 events.
[13:54:50.771] INFO: 104000 events read in total (12447ms).
[13:54:50.781] INFO: Test took 13830ms.
[13:54:50.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:51.177] INFO: dacScan step from 21 .. 21
[13:54:51.177] INFO: dacScan split into 1 runs with ntrig = 25
[13:54:51.177] INFO: run 1 of 1
[13:54:52.023] INFO: Expecting 104000 events.
[13:55:04.559] INFO: 104000 events read in total (12009ms).
[13:55:04.569] INFO: Test took 13391ms.
[13:55:04.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:04.955] INFO: dacScan step from 22 .. 22
[13:55:04.955] INFO: dacScan split into 1 runs with ntrig = 25
[13:55:04.955] INFO: run 1 of 1
[13:55:05.807] INFO: Expecting 104000 events.
[13:55:18.178] INFO: 104000 events read in total (11844ms).
[13:55:18.187] INFO: Test took 13231ms.
[13:55:18.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:18.583] INFO: dacScan step from 23 .. 23
[13:55:18.583] INFO: dacScan split into 1 runs with ntrig = 25
[13:55:18.584] INFO: run 1 of 1
[13:55:19.419] INFO: Expecting 104000 events.
[13:55:31.525] INFO: 104000 events read in total (11579ms).
[13:55:31.535] INFO: Test took 12951ms.
[13:55:31.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:31.928] INFO: dacScan step from 24 .. 24
[13:55:31.928] INFO: dacScan split into 1 runs with ntrig = 25
[13:55:31.928] INFO: run 1 of 1
[13:55:32.777] INFO: Expecting 104000 events.
[13:55:44.821] INFO: 104000 events read in total (11517ms).
[13:55:44.830] INFO: Test took 12901ms.
[13:55:44.920] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:45.222] INFO: dacScan step from 25 .. 25
[13:55:45.222] INFO: dacScan split into 1 runs with ntrig = 25
[13:55:45.222] INFO: run 1 of 1
[13:55:46.071] INFO: Expecting 104000 events.
[13:55:58.126] INFO: 104000 events read in total (11528ms).
[13:55:58.136] INFO: Test took 12913ms.
[13:55:58.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:58.534] INFO: dacScan step from 26 .. 26
[13:55:58.534] INFO: dacScan split into 1 runs with ntrig = 25
[13:55:58.534] INFO: run 1 of 1
[13:55:59.376] INFO: Expecting 104000 events.
[13:56:11.314] INFO: 104000 events read in total (11411ms).
[13:56:11.324] INFO: Test took 12789ms.
[13:56:11.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:11.715] INFO: dacScan step from 27 .. 27
[13:56:11.715] INFO: dacScan split into 1 runs with ntrig = 25
[13:56:11.715] INFO: run 1 of 1
[13:56:12.563] INFO: Expecting 104000 events.
[13:56:24.205] INFO: 104000 events read in total (11115ms).
[13:56:24.216] INFO: Test took 12500ms.
[13:56:24.305] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:24.609] INFO: dacScan step from 28 .. 28
[13:56:24.609] INFO: dacScan split into 1 runs with ntrig = 25
[13:56:24.610] INFO: run 1 of 1
[13:56:25.467] INFO: Expecting 104000 events.
[13:56:37.294] INFO: 104000 events read in total (11300ms).
[13:56:37.304] INFO: Test took 12694ms.
[13:56:37.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:37.707] INFO: dacScan step from 29 .. 29
[13:56:37.707] INFO: dacScan split into 1 runs with ntrig = 25
[13:56:37.707] INFO: run 1 of 1
[13:56:38.552] INFO: Expecting 104000 events.
[13:56:50.065] INFO: 104000 events read in total (10986ms).
[13:56:50.076] INFO: Test took 12369ms.
[13:56:50.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:50.471] INFO: dacScan step from 30 .. 30
[13:56:50.471] INFO: dacScan split into 1 runs with ntrig = 25
[13:56:50.471] INFO: run 1 of 1
[13:56:51.318] INFO: Expecting 104000 events.
[13:57:03.058] INFO: 104000 events read in total (11212ms).
[13:57:03.067] INFO: Test took 12595ms.
[13:57:03.155] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:03.458] INFO: dacScan step from 31 .. 31
[13:57:03.458] INFO: dacScan split into 1 runs with ntrig = 25
[13:57:03.458] INFO: run 1 of 1
[13:57:04.301] INFO: Expecting 104000 events.
[13:57:15.915] INFO: 104000 events read in total (11087ms).
[13:57:15.925] INFO: Test took 12466ms.
[13:57:16.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:16.324] INFO: dacScan step from 32 .. 32
[13:57:16.324] INFO: dacScan split into 1 runs with ntrig = 25
[13:57:16.324] INFO: run 1 of 1
[13:57:17.177] INFO: Expecting 104000 events.
[13:57:29.084] INFO: 104000 events read in total (11380ms).
[13:57:29.094] INFO: Test took 12769ms.
[13:57:29.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:29.495] INFO: dacScan step from 33 .. 33
[13:57:29.495] INFO: dacScan split into 1 runs with ntrig = 25
[13:57:29.495] INFO: run 1 of 1
[13:57:30.341] INFO: Expecting 104000 events.
[13:57:42.367] INFO: 104000 events read in total (11499ms).
[13:57:42.377] INFO: Test took 12881ms.
[13:57:42.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:42.776] INFO: dacScan step from 34 .. 34
[13:57:42.776] INFO: dacScan split into 1 runs with ntrig = 25
[13:57:42.776] INFO: run 1 of 1
[13:57:43.626] INFO: Expecting 104000 events.
[13:57:55.840] INFO: 104000 events read in total (11687ms).
[13:57:55.850] INFO: Test took 13074ms.
[13:57:55.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:56.241] INFO: dacScan step from 35 .. 35
[13:57:56.241] INFO: dacScan split into 1 runs with ntrig = 25
[13:57:56.241] INFO: run 1 of 1
[13:57:57.082] INFO: Expecting 104000 events.
[13:58:09.370] INFO: 104000 events read in total (11761ms).
[13:58:09.379] INFO: Test took 13137ms.
[13:58:09.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:09.777] INFO: dacScan step from 36 .. 36
[13:58:09.777] INFO: dacScan split into 1 runs with ntrig = 25
[13:58:09.778] INFO: run 1 of 1
[13:58:10.606] INFO: Expecting 104000 events.
[13:58:23.168] INFO: 104000 events read in total (12035ms).
[13:58:23.179] INFO: Test took 13401ms.
[13:58:23.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:23.568] INFO: dacScan step from 37 .. 37
[13:58:23.568] INFO: dacScan split into 1 runs with ntrig = 25
[13:58:23.568] INFO: run 1 of 1
[13:58:24.401] INFO: Expecting 104000 events.
[13:58:36.987] INFO: 104000 events read in total (12059ms).
[13:58:36.997] INFO: Test took 13428ms.
[13:58:37.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:37.387] INFO: dacScan step from 38 .. 38
[13:58:37.387] INFO: dacScan split into 1 runs with ntrig = 25
[13:58:37.387] INFO: run 1 of 1
[13:58:38.219] INFO: Expecting 104000 events.
[13:58:51.286] INFO: 104000 events read in total (12540ms).
[13:58:51.295] INFO: Test took 13907ms.
[13:58:51.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:51.682] INFO: dacScan step from 39 .. 39
[13:58:51.683] INFO: dacScan split into 1 runs with ntrig = 25
[13:58:51.683] INFO: run 1 of 1
[13:58:52.505] INFO: Expecting 104000 events.
[13:59:05.520] INFO: 104000 events read in total (12488ms).
[13:59:05.530] INFO: Test took 13847ms.
[13:59:05.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:05.921] INFO: dacScan step from 40 .. 40
[13:59:05.921] INFO: dacScan split into 1 runs with ntrig = 25
[13:59:05.921] INFO: run 1 of 1
[13:59:06.749] INFO: Expecting 104000 events.
[13:59:20.147] INFO: 104000 events read in total (12871ms).
[13:59:20.162] INFO: Test took 14240ms.
[13:59:20.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:20.546] INFO: dacScan step from 41 .. 41
[13:59:20.546] INFO: dacScan split into 1 runs with ntrig = 25
[13:59:20.546] INFO: run 1 of 1
[13:59:21.384] INFO: Expecting 104000 events.
[13:59:35.148] INFO: 104000 events read in total (13237ms).
[13:59:35.159] INFO: Test took 14612ms.
[13:59:35.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:35.551] INFO: dacScan step from 42 .. 42
[13:59:35.551] INFO: dacScan split into 1 runs with ntrig = 25
[13:59:35.551] INFO: run 1 of 1
[13:59:36.388] INFO: Expecting 104000 events.
[13:59:50.805] INFO: 104000 events read in total (13890ms).
[13:59:50.814] INFO: Test took 15262ms.
[13:59:50.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:51.206] INFO: dacScan step from 43 .. 43
[13:59:51.206] INFO: dacScan split into 1 runs with ntrig = 25
[13:59:51.206] INFO: run 1 of 1
[13:59:52.030] INFO: Expecting 104000 events.
[14:00:06.827] INFO: 104000 events read in total (14270ms).
[14:00:06.837] INFO: Test took 15630ms.
[14:00:06.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:07.232] INFO: dacScan step from 44 .. 44
[14:00:07.232] INFO: dacScan split into 1 runs with ntrig = 25
[14:00:07.232] INFO: run 1 of 1
[14:00:08.073] INFO: Expecting 104000 events.
[14:00:23.083] INFO: 104000 events read in total (14483ms).
[14:00:23.092] INFO: Test took 15859ms.
[14:00:23.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:23.481] INFO: dacScan step from 45 .. 45
[14:00:23.481] INFO: dacScan split into 1 runs with ntrig = 25
[14:00:23.481] INFO: run 1 of 1
[14:00:24.312] INFO: Expecting 104000 events.
[14:00:39.341] INFO: 104000 events read in total (14502ms).
[14:00:39.351] INFO: Test took 15870ms.
[14:00:39.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:39.749] INFO: dacScan step from 46 .. 46
[14:00:39.749] INFO: dacScan split into 1 runs with ntrig = 25
[14:00:39.750] INFO: run 1 of 1
[14:00:40.587] INFO: Expecting 104000 events.
[14:00:55.988] INFO: 104000 events read in total (14874ms).
[14:00:55.998] INFO: Test took 16247ms.
[14:00:56.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:56.386] INFO: dacScan step from 47 .. 47
[14:00:56.386] INFO: dacScan split into 1 runs with ntrig = 25
[14:00:56.386] INFO: run 1 of 1
[14:00:57.218] INFO: Expecting 104000 events.
[14:01:13.113] INFO: 104000 events read in total (15368ms).
[14:01:13.123] INFO: Test took 16736ms.
[14:01:13.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:13.544] INFO: dacScan step from 48 .. 48
[14:01:13.544] INFO: dacScan split into 1 runs with ntrig = 25
[14:01:13.544] INFO: run 1 of 1
[14:01:14.402] INFO: Expecting 104000 events.
[14:01:30.801] INFO: 104000 events read in total (15872ms).
[14:01:30.820] INFO: Test took 17275ms.
[14:01:30.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:31.234] INFO: dacScan step from 49 .. 49
[14:01:31.234] INFO: dacScan split into 1 runs with ntrig = 25
[14:01:31.234] INFO: run 1 of 1
[14:01:32.082] INFO: Expecting 104000 events.
[14:01:48.369] INFO: 104000 events read in total (15760ms).
[14:01:48.379] INFO: Test took 17144ms.
[14:01:48.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:48.788] INFO: dacScan step from 50 .. 50
[14:01:48.788] INFO: dacScan split into 1 runs with ntrig = 25
[14:01:48.788] INFO: run 1 of 1
[14:01:49.639] INFO: Expecting 104000 events.
[14:02:05.992] INFO: 104000 events read in total (15824ms).
[14:02:06.003] INFO: Test took 17214ms.
[14:02:06.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:06.402] INFO: dacScan step from 51 .. 51
[14:02:06.402] INFO: dacScan split into 1 runs with ntrig = 25
[14:02:06.402] INFO: run 1 of 1
[14:02:07.253] INFO: Expecting 104000 events.
[14:02:23.615] INFO: 104000 events read in total (15835ms).
[14:02:23.626] INFO: Test took 17223ms.
[14:02:23.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:24.036] INFO: dacScan step from 52 .. 52
[14:02:24.036] INFO: dacScan split into 1 runs with ntrig = 25
[14:02:24.036] INFO: run 1 of 1
[14:02:24.879] INFO: Expecting 104000 events.
[14:02:40.737] INFO: 104000 events read in total (15331ms).
[14:02:40.752] INFO: Test took 16715ms.
[14:02:40.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:41.176] INFO: dacScan step from 53 .. 53
[14:02:41.176] INFO: dacScan split into 1 runs with ntrig = 25
[14:02:41.176] INFO: run 1 of 1
[14:02:42.020] INFO: Expecting 104000 events.
[14:02:57.318] INFO: 104000 events read in total (14771ms).
[14:02:57.329] INFO: Test took 16152ms.
[14:02:57.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:57.736] INFO: dacScan step from 54 .. 54
[14:02:57.736] INFO: dacScan split into 1 runs with ntrig = 25
[14:02:57.736] INFO: run 1 of 1
[14:02:58.584] INFO: Expecting 104000 events.
[14:03:14.322] INFO: 104000 events read in total (15211ms).
[14:03:14.340] INFO: Test took 16603ms.
[14:03:14.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:14.747] INFO: dacScan step from 55 .. 55
[14:03:14.747] INFO: dacScan split into 1 runs with ntrig = 25
[14:03:14.747] INFO: run 1 of 1
[14:03:15.599] INFO: Expecting 104000 events.
[14:03:30.810] INFO: 104000 events read in total (14684ms).
[14:03:30.820] INFO: Test took 16071ms.
[14:03:30.902] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:31.224] INFO: dacScan step from 56 .. 56
[14:03:31.224] INFO: dacScan split into 1 runs with ntrig = 25
[14:03:31.224] INFO: run 1 of 1
[14:03:32.077] INFO: Expecting 104000 events.
[14:03:47.548] INFO: 104000 events read in total (14944ms).
[14:03:47.563] INFO: Test took 16338ms.
[14:03:47.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:47.976] INFO: dacScan step from 57 .. 57
[14:03:47.976] INFO: dacScan split into 1 runs with ntrig = 25
[14:03:47.976] INFO: run 1 of 1
[14:03:48.826] INFO: Expecting 104000 events.
[14:04:04.658] INFO: 104000 events read in total (15305ms).
[14:04:04.670] INFO: Test took 16693ms.
[14:04:04.770] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:05.090] INFO: dacScan step from 58 .. 58
[14:04:05.090] INFO: dacScan split into 1 runs with ntrig = 25
[14:04:05.090] INFO: run 1 of 1
[14:04:05.938] INFO: Expecting 104000 events.
[14:04:21.381] INFO: 104000 events read in total (14916ms).
[14:04:21.391] INFO: Test took 16300ms.
[14:04:21.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:21.798] INFO: dacScan step from 59 .. 59
[14:04:21.799] INFO: dacScan split into 1 runs with ntrig = 25
[14:04:21.799] INFO: run 1 of 1
[14:04:22.645] INFO: Expecting 104000 events.
[14:04:38.122] INFO: 104000 events read in total (14950ms).
[14:04:38.132] INFO: Test took 16332ms.
[14:04:38.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:38.542] INFO: dacScan step from 60 .. 60
[14:04:38.542] INFO: dacScan split into 1 runs with ntrig = 25
[14:04:38.542] INFO: run 1 of 1
[14:04:39.394] INFO: Expecting 104000 events.
[14:04:54.738] INFO: 104000 events read in total (14817ms).
[14:04:54.748] INFO: Test took 16205ms.
[14:04:54.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:55.158] INFO: dacScan step from 61 .. 61
[14:04:55.158] INFO: dacScan split into 1 runs with ntrig = 25
[14:04:55.158] INFO: run 1 of 1
[14:04:56.010] INFO: Expecting 104000 events.
[14:05:11.460] INFO: 104000 events read in total (14923ms).
[14:05:11.471] INFO: Test took 16311ms.
[14:05:11.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:11.894] INFO: dacScan step from 62 .. 62
[14:05:11.894] INFO: dacScan split into 1 runs with ntrig = 25
[14:05:11.894] INFO: run 1 of 1
[14:05:12.743] INFO: Expecting 104000 events.
[14:05:28.211] INFO: 104000 events read in total (14941ms).
[14:05:28.222] INFO: Test took 16327ms.
[14:05:28.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:28.628] INFO: dacScan step from 63 .. 63
[14:05:28.628] INFO: dacScan split into 1 runs with ntrig = 25
[14:05:28.628] INFO: run 1 of 1
[14:05:29.480] INFO: Expecting 104000 events.
[14:05:45.188] INFO: 104000 events read in total (15181ms).
[14:05:45.202] INFO: Test took 16573ms.
[14:05:45.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:45.618] INFO: dacScan step from 64 .. 64
[14:05:45.618] INFO: dacScan split into 1 runs with ntrig = 25
[14:05:45.618] INFO: run 1 of 1
[14:05:46.470] INFO: Expecting 104000 events.
[14:06:02.123] INFO: 104000 events read in total (15126ms).
[14:06:02.133] INFO: Test took 16514ms.
[14:06:02.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:02.549] INFO: dacScan step from 65 .. 65
[14:06:02.549] INFO: dacScan split into 1 runs with ntrig = 25
[14:06:02.549] INFO: run 1 of 1
[14:06:03.396] INFO: Expecting 104000 events.
[14:06:19.065] INFO: 104000 events read in total (15142ms).
[14:06:19.076] INFO: Test took 16526ms.
[14:06:19.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:19.491] INFO: dacScan step from 66 .. 66
[14:06:19.491] INFO: dacScan split into 1 runs with ntrig = 25
[14:06:19.491] INFO: run 1 of 1
[14:06:20.344] INFO: Expecting 104000 events.
[14:06:35.839] INFO: 104000 events read in total (14968ms).
[14:06:35.850] INFO: Test took 16358ms.
[14:06:35.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:36.272] INFO: dacScan step from 67 .. 67
[14:06:36.272] INFO: dacScan split into 1 runs with ntrig = 25
[14:06:36.272] INFO: run 1 of 1
[14:06:37.125] INFO: Expecting 104000 events.
[14:06:52.137] INFO: 104000 events read in total (14484ms).
[14:06:52.147] INFO: Test took 15874ms.
[14:06:52.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:52.563] INFO: dacScan step from 68 .. 68
[14:06:52.563] INFO: dacScan split into 1 runs with ntrig = 25
[14:06:52.563] INFO: run 1 of 1
[14:06:53.416] INFO: Expecting 104000 events.
[14:07:09.089] INFO: 104000 events read in total (15147ms).
[14:07:09.103] INFO: Test took 16539ms.
[14:07:09.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:09.517] INFO: dacScan step from 69 .. 69
[14:07:09.517] INFO: dacScan split into 1 runs with ntrig = 25
[14:07:09.517] INFO: run 1 of 1
[14:07:10.363] INFO: Expecting 104000 events.
[14:07:25.866] INFO: 104000 events read in total (14976ms).
[14:07:25.877] INFO: Test took 16359ms.
[14:07:25.980] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:26.299] INFO: dacScan step from 70 .. 70
[14:07:26.299] INFO: dacScan split into 1 runs with ntrig = 25
[14:07:26.299] INFO: run 1 of 1
[14:07:27.151] INFO: Expecting 104000 events.
[14:07:42.623] INFO: 104000 events read in total (14945ms).
[14:07:42.633] INFO: Test took 16333ms.
[14:07:42.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:43.043] INFO: dacScan step from 71 .. 71
[14:07:43.044] INFO: dacScan split into 1 runs with ntrig = 25
[14:07:43.044] INFO: run 1 of 1
[14:07:43.894] INFO: Expecting 104000 events.
[14:07:59.823] INFO: 104000 events read in total (15402ms).
[14:07:59.833] INFO: Test took 16788ms.
[14:07:59.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:00.241] INFO: dacScan step from 72 .. 72
[14:08:00.241] INFO: dacScan split into 1 runs with ntrig = 25
[14:08:00.241] INFO: run 1 of 1
[14:08:01.092] INFO: Expecting 104000 events.
[14:08:16.429] INFO: 104000 events read in total (14810ms).
[14:08:16.439] INFO: Test took 16196ms.
[14:08:16.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:16.829] INFO: dacScan step from 73 .. 73
[14:08:16.829] INFO: dacScan split into 1 runs with ntrig = 25
[14:08:16.829] INFO: run 1 of 1
[14:08:17.669] INFO: Expecting 104000 events.
[14:08:33.485] INFO: 104000 events read in total (15289ms).
[14:08:33.496] INFO: Test took 16666ms.
[14:08:33.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:33.878] INFO: dacScan step from 74 .. 74
[14:08:33.878] INFO: dacScan split into 1 runs with ntrig = 25
[14:08:33.878] INFO: run 1 of 1
[14:08:34.716] INFO: Expecting 104000 events.
[14:08:50.642] INFO: 104000 events read in total (15399ms).
[14:08:50.651] INFO: Test took 16771ms.
[14:08:50.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:51.039] INFO: dacScan step from 75 .. 75
[14:08:51.039] INFO: dacScan split into 1 runs with ntrig = 25
[14:08:51.039] INFO: run 1 of 1
[14:08:51.868] INFO: Expecting 104000 events.
[14:09:07.792] INFO: 104000 events read in total (15397ms).
[14:09:07.802] INFO: Test took 16761ms.
[14:09:07.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:08.185] INFO: dacScan step from 76 .. 76
[14:09:08.185] INFO: dacScan split into 1 runs with ntrig = 25
[14:09:08.185] INFO: run 1 of 1
[14:09:09.009] INFO: Expecting 104000 events.
[14:09:25.495] INFO: 104000 events read in total (15959ms).
[14:09:25.505] INFO: Test took 17319ms.
[14:09:25.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:25.900] INFO: dacScan step from 77 .. 77
[14:09:25.900] INFO: dacScan split into 1 runs with ntrig = 25
[14:09:25.900] INFO: run 1 of 1
[14:09:26.731] INFO: Expecting 104000 events.
[14:09:43.123] INFO: 104000 events read in total (15866ms).
[14:09:43.134] INFO: Test took 17233ms.
[14:09:43.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:43.534] INFO: dacScan step from 78 .. 78
[14:09:43.534] INFO: dacScan split into 1 runs with ntrig = 25
[14:09:43.534] INFO: run 1 of 1
[14:09:44.372] INFO: Expecting 104000 events.
[14:10:00.503] INFO: 104000 events read in total (15604ms).
[14:10:00.515] INFO: Test took 16979ms.
[14:10:00.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:00.919] INFO: dacScan step from 79 .. 79
[14:10:00.919] INFO: dacScan split into 1 runs with ntrig = 25
[14:10:00.919] INFO: run 1 of 1
[14:10:01.762] INFO: Expecting 104000 events.
[14:10:18.034] INFO: 104000 events read in total (15745ms).
[14:10:18.045] INFO: Test took 17125ms.
[14:10:18.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:18.445] INFO: dacScan step from 80 .. 80
[14:10:18.445] INFO: dacScan split into 1 runs with ntrig = 25
[14:10:18.445] INFO: run 1 of 1
[14:10:19.288] INFO: Expecting 104000 events.
[14:10:35.721] INFO: 104000 events read in total (15906ms).
[14:10:35.731] INFO: Test took 17284ms.
[14:10:35.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:36.143] INFO: dacScan step from 81 .. 81
[14:10:36.143] INFO: dacScan split into 1 runs with ntrig = 25
[14:10:36.143] INFO: run 1 of 1
[14:10:36.988] INFO: Expecting 104000 events.
[14:10:52.740] INFO: 104000 events read in total (15225ms).
[14:10:52.750] INFO: Test took 16606ms.
[14:10:52.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:53.143] INFO: dacScan step from 82 .. 82
[14:10:53.143] INFO: dacScan split into 1 runs with ntrig = 25
[14:10:53.143] INFO: run 1 of 1
[14:10:53.988] INFO: Expecting 104000 events.
[14:11:09.867] INFO: 104000 events read in total (15352ms).
[14:11:09.883] INFO: Test took 16738ms.
[14:11:09.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:10.292] INFO: dacScan step from 83 .. 83
[14:11:10.292] INFO: dacScan split into 1 runs with ntrig = 25
[14:11:10.292] INFO: run 1 of 1
[14:11:11.144] INFO: Expecting 104000 events.
[14:11:26.639] INFO: 104000 events read in total (14968ms).
[14:11:26.650] INFO: Test took 16357ms.
[14:11:26.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:27.059] INFO: dacScan step from 84 .. 84
[14:11:27.060] INFO: dacScan split into 1 runs with ntrig = 25
[14:11:27.060] INFO: run 1 of 1
[14:11:27.909] INFO: Expecting 104000 events.
[14:11:43.620] INFO: 104000 events read in total (15184ms).
[14:11:43.630] INFO: Test took 16569ms.
[14:11:43.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:44.042] INFO: dacScan step from 85 .. 85
[14:11:44.042] INFO: dacScan split into 1 runs with ntrig = 25
[14:11:44.042] INFO: run 1 of 1
[14:11:44.891] INFO: Expecting 104000 events.
[14:12:00.145] INFO: 104000 events read in total (14727ms).
[14:12:00.154] INFO: Test took 16110ms.
[14:12:00.242] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:00.558] INFO: dacScan step from 86 .. 86
[14:12:00.558] INFO: dacScan split into 1 runs with ntrig = 25
[14:12:00.558] INFO: run 1 of 1
[14:12:01.411] INFO: Expecting 104000 events.
[14:12:16.900] INFO: 104000 events read in total (14962ms).
[14:12:16.910] INFO: Test took 16350ms.
[14:12:16.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:17.314] INFO: dacScan step from 87 .. 87
[14:12:17.314] INFO: dacScan split into 1 runs with ntrig = 25
[14:12:17.314] INFO: run 1 of 1
[14:12:18.162] INFO: Expecting 104000 events.
[14:12:33.640] INFO: 104000 events read in total (14951ms).
[14:12:33.651] INFO: Test took 16336ms.
[14:12:33.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:34.055] INFO: dacScan step from 88 .. 88
[14:12:34.055] INFO: dacScan split into 1 runs with ntrig = 25
[14:12:34.055] INFO: run 1 of 1
[14:12:34.902] INFO: Expecting 104000 events.
[14:12:50.199] INFO: 104000 events read in total (14760ms).
[14:12:50.210] INFO: Test took 16154ms.
[14:12:50.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:50.633] INFO: dacScan step from 89 .. 89
[14:12:50.633] INFO: dacScan split into 1 runs with ntrig = 25
[14:12:50.633] INFO: run 1 of 1
[14:12:51.486] INFO: Expecting 104000 events.
[14:13:07.331] INFO: 104000 events read in total (15318ms).
[14:13:07.341] INFO: Test took 16706ms.
[14:13:07.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:07.740] INFO: dacScan step from 90 .. 90
[14:13:07.740] INFO: dacScan split into 1 runs with ntrig = 25
[14:13:07.740] INFO: run 1 of 1
[14:13:08.588] INFO: Expecting 104000 events.
[14:13:23.761] INFO: 104000 events read in total (14646ms).
[14:13:23.771] INFO: Test took 16029ms.
[14:13:23.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:24.179] INFO: dacScan step from 91 .. 91
[14:13:24.179] INFO: dacScan split into 1 runs with ntrig = 25
[14:13:24.179] INFO: run 1 of 1
[14:13:25.033] INFO: Expecting 104000 events.
[14:13:40.668] INFO: 104000 events read in total (15108ms).
[14:13:40.678] INFO: Test took 16497ms.
[14:13:40.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:41.088] INFO: dacScan step from 92 .. 92
[14:13:41.088] INFO: dacScan split into 1 runs with ntrig = 25
[14:13:41.088] INFO: run 1 of 1
[14:13:41.935] INFO: Expecting 104000 events.
[14:13:57.575] INFO: 104000 events read in total (15114ms).
[14:13:57.586] INFO: Test took 16497ms.
[14:13:57.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:57.995] INFO: dacScan step from 93 .. 93
[14:13:57.995] INFO: dacScan split into 1 runs with ntrig = 25
[14:13:57.995] INFO: run 1 of 1
[14:13:58.843] INFO: Expecting 104000 events.
[14:14:14.515] INFO: 104000 events read in total (15145ms).
[14:14:14.526] INFO: Test took 16530ms.
[14:14:14.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:14.921] INFO: dacScan step from 94 .. 94
[14:14:14.921] INFO: dacScan split into 1 runs with ntrig = 25
[14:14:14.921] INFO: run 1 of 1
[14:14:15.772] INFO: Expecting 104000 events.
[14:14:30.932] INFO: 104000 events read in total (14633ms).
[14:14:30.943] INFO: Test took 16020ms.
[14:14:31.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:31.350] INFO: dacScan step from 95 .. 95
[14:14:31.350] INFO: dacScan split into 1 runs with ntrig = 25
[14:14:31.350] INFO: run 1 of 1
[14:14:32.199] INFO: Expecting 104000 events.
[14:14:47.318] INFO: 104000 events read in total (14592ms).
[14:14:47.328] INFO: Test took 15976ms.
[14:14:47.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:47.723] INFO: dacScan step from 96 .. 96
[14:14:47.724] INFO: dacScan split into 1 runs with ntrig = 25
[14:14:47.724] INFO: run 1 of 1
[14:14:48.574] INFO: Expecting 104000 events.
[14:15:04.227] INFO: 104000 events read in total (15120ms).
[14:15:04.242] INFO: Test took 16517ms.
[14:15:04.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:04.643] INFO: dacScan step from 97 .. 97
[14:15:04.643] INFO: dacScan split into 1 runs with ntrig = 25
[14:15:04.643] INFO: run 1 of 1
[14:15:05.497] INFO: Expecting 104000 events.
[14:15:20.659] INFO: 104000 events read in total (14634ms).
[14:15:20.669] INFO: Test took 16025ms.
[14:15:20.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:21.072] INFO: dacScan step from 98 .. 98
[14:15:21.072] INFO: dacScan split into 1 runs with ntrig = 25
[14:15:21.072] INFO: run 1 of 1
[14:15:21.922] INFO: Expecting 104000 events.
[14:15:37.172] INFO: 104000 events read in total (14723ms).
[14:15:37.182] INFO: Test took 16108ms.
[14:15:37.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:37.580] INFO: dacScan step from 99 .. 99
[14:15:37.580] INFO: dacScan split into 1 runs with ntrig = 25
[14:15:37.580] INFO: run 1 of 1
[14:15:38.433] INFO: Expecting 104000 events.
[14:15:54.255] INFO: 104000 events read in total (15295ms).
[14:15:54.266] INFO: Test took 16684ms.
[14:15:54.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:54.646] INFO: dacScan step from 100 .. 100
[14:15:54.646] INFO: dacScan split into 1 runs with ntrig = 25
[14:15:54.646] INFO: run 1 of 1
[14:15:55.496] INFO: Expecting 104000 events.
[14:16:10.872] INFO: 104000 events read in total (14849ms).
[14:16:10.881] INFO: Test took 16233ms.
[14:16:10.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:11.266] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:13.324] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:15.420] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:17.515] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:19.705] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:21.898] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:24.108] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:26.220] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:28.322] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:30.484] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:32.689] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:34.912] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:37.112] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:39.306] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:41.356] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:43.367] INFO: dumping ASCII scurve output file: XSCurveData
[14:16:45.427] INFO: PixTest:: pg_setup set to default.
[14:16:45.431] INFO: vcal mean: 40.22 40.68 38.87 42.22 42.02 43.74 41.73 42.16 41.84 43.39 42.60 42.39 43.11 39.73 41.50 40.24
[14:16:45.431] INFO: vcal RMS: 1.39 1.49 3.63 2.23 1.79 1.60 1.60 1.58 1.67 1.65 1.64 1.73 1.62 1.50 1.52 1.47
[14:16:45.431] INFO: number of X-ray hits detected: 146429 151236 128715 192125 191557 212615 190396 193747 196222 207364 222375 203353 203438 132450 155152 151527
[14:16:45.431] INFO: number of triggers sent (total per ROC): 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000 104000
[14:16:45.431] INFO: X-ray hit rate [MHz/cm2]: 85.8 88.7 75.5 112.6 112.3 124.6 111.6 113.6 115.0 121.6 130.4 119.2 119.3 77.6 91.0 88.8
[14:16:45.431] INFO: PixTestHighRate::doXNoiseMaps() done
[14:16:45.564] INFO: enter test to run
[14:16:45.564] INFO: test: exit no parameter change
[14:16:45.666] QUIET: Connection to board 172 closed.
[14:16:45.682] INFO: pXar: this is the end, my friend
pxar.log
[14:17:53.151] INFO: *** Welcome to pxar ***
[14:17:53.151] INFO: *** Today: 2015/09/09
[14:17:53.152] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[14:17:53.154] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[14:17:53.154] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[14:17:53.154] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[14:17:53.245] INFO: clk: 4
[14:17:53.245] INFO: ctr: 4
[14:17:53.245] INFO: sda: 19
[14:17:53.245] INFO: tin: 9
[14:17:53.245] INFO: level: 15
[14:17:53.245] INFO: triggerdelay: 0
[14:17:53.245] QUIET: Instanciating API for pxar 2.5
[14:17:53.245] INFO: Log level: INFO
[14:17:53.253] INFO: Found DTB DTB_WZ4QKL
[14:17:53.263] QUIET: Connection to board DTB_WZ4QKL opened.
[14:17:53.267] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[14:17:53.270] INFO: RPC call hashes of host and DTB match: 397073690
[14:17:55.103] INFO: DUT info:
[14:17:55.103] INFO: The DUT currently contains the following objects:
[14:17:55.103] INFO: 2 TBM Cores tbm08c (2 ON)
[14:17:55.104] INFO: TBM Core alpha (0): 7 registers set
[14:17:55.104] INFO: TBM Core beta (1): 7 registers set
[14:17:55.104] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:17:55.104] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.104] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.105] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.105] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.105] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.105] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.105] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:17:55.506] INFO: enter 'restricted' command line mode
[14:17:55.507] INFO: enter test to run
[14:17:55.507] INFO: test: highrate no parameter change
[14:17:55.507] INFO: running: highrate
[14:17:55.516] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[14:17:55.758] INFO: ----------------------------------------------------------------------
[14:17:55.758] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:17:55.758] INFO: ----------------------------------------------------------------------
[14:17:55.903] INFO: Expecting 768 events.
[14:17:57.185] INFO: 768 events read in total (499ms).
[14:17:57.359] INFO: Test took 1594ms.
[14:17:58.220] INFO: Expecting 41600 events.
[14:18:03.094] INFO: 41600 events read in total (4346ms).
[14:18:03.098] INFO: Test took 5729ms.
[14:18:03.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:04.089] INFO: Expecting 41600 events.
[14:18:09.283] INFO: 41600 events read in total (4667ms).
[14:18:09.286] INFO: Test took 6046ms.
[14:18:09.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:10.282] INFO: Expecting 41600 events.
[14:18:15.542] INFO: 41600 events read in total (4733ms).
[14:18:15.545] INFO: Test took 6114ms.
[14:18:15.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:16.534] INFO: Expecting 41600 events.
[14:18:21.806] INFO: 41600 events read in total (4745ms).
[14:18:21.809] INFO: Test took 6119ms.
[14:18:21.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:22.800] INFO: Expecting 41600 events.
[14:18:28.017] INFO: 41600 events read in total (4690ms).
[14:18:28.021] INFO: Test took 6063ms.
[14:18:28.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:29.036] INFO: Expecting 41600 events.
[14:18:34.183] INFO: 41600 events read in total (4620ms).
[14:18:34.187] INFO: Test took 6018ms.
[14:18:34.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:35.193] INFO: Expecting 41600 events.
[14:18:40.255] INFO: 41600 events read in total (4535ms).
[14:18:40.258] INFO: Test took 5922ms.
[14:18:40.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:41.258] INFO: Expecting 41600 events.
[14:18:46.272] INFO: 41600 events read in total (4487ms).
[14:18:46.276] INFO: Test took 5872ms.
[14:18:46.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:47.292] INFO: Expecting 41600 events.
[14:18:52.419] INFO: 41600 events read in total (4600ms).
[14:18:52.426] INFO: Test took 5999ms.
[14:18:52.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:53.435] INFO: Expecting 41600 events.
[14:18:58.507] INFO: 41600 events read in total (4546ms).
[14:18:58.511] INFO: Test took 5933ms.
[14:18:58.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:59.511] INFO: Expecting 41600 events.
[14:19:04.796] INFO: 41600 events read in total (4758ms).
[14:19:04.800] INFO: Test took 6143ms.
[14:19:04.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:05.793] INFO: Expecting 41600 events.
[14:19:10.987] INFO: 41600 events read in total (4667ms).
[14:19:10.990] INFO: Test took 6042ms.
[14:19:11.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:11.985] INFO: Expecting 41600 events.
[14:19:16.950] INFO: 41600 events read in total (4438ms).
[14:19:16.954] INFO: Test took 5813ms.
[14:19:17.043] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:17.954] INFO: Expecting 41600 events.
[14:19:22.825] INFO: 41600 events read in total (4344ms).
[14:19:22.828] INFO: Test took 5727ms.
[14:19:22.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:23.821] INFO: Expecting 41600 events.
[14:19:28.871] INFO: 41600 events read in total (4523ms).
[14:19:28.875] INFO: Test took 5896ms.
[14:19:28.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:29.866] INFO: Expecting 41600 events.
[14:19:34.713] INFO: 41600 events read in total (4320ms).
[14:19:34.716] INFO: Test took 5695ms.
[14:19:34.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:35.716] INFO: Expecting 41600 events.
[14:19:40.718] INFO: 41600 events read in total (4475ms).
[14:19:40.722] INFO: Test took 5853ms.
[14:19:40.814] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:41.716] INFO: Expecting 41600 events.
[14:19:46.660] INFO: 41600 events read in total (4417ms).
[14:19:46.663] INFO: Test took 5793ms.
[14:19:46.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:47.665] INFO: Expecting 41600 events.
[14:19:52.567] INFO: 41600 events read in total (4375ms).
[14:19:52.570] INFO: Test took 5760ms.
[14:19:52.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:53.570] INFO: Expecting 41600 events.
[14:19:58.090] INFO: 41600 events read in total (3993ms).
[14:19:58.093] INFO: Test took 5368ms.
[14:19:58.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:58.613] INFO: enter test to run
[14:19:58.613] INFO: test: savedacs no parameter change
[14:19:58.613] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat
[14:19:58.613] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C1.dat
[14:19:58.613] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C2.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C3.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C4.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C5.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C6.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C7.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C8.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C9.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C10.dat
[14:19:58.614] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C11.dat
[14:19:58.615] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C12.dat
[14:19:58.615] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C13.dat
[14:19:58.615] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C14.dat
[14:19:58.615] INFO: write dac parameters into /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[14:19:58.615] INFO: enter test to run
[14:19:58.615] INFO: test: exit no parameter change
[14:19:58.734] QUIET: Connection to board 172 closed.
[14:19:58.750] INFO: pXar: this is the end, my friend
pxar.log
[14:20:04.310] INFO: *** Welcome to pxar ***
[14:20:04.310] INFO: *** Today: 2015/09/09
[14:20:04.310] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[14:20:04.312] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[14:20:04.313] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[14:20:04.313] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[14:20:04.400] INFO: clk: 4
[14:20:04.400] INFO: ctr: 4
[14:20:04.400] INFO: sda: 19
[14:20:04.400] INFO: tin: 9
[14:20:04.400] INFO: level: 15
[14:20:04.400] INFO: triggerdelay: 0
[14:20:04.400] QUIET: Instanciating API for pxar 2.5
[14:20:04.400] INFO: Log level: INFO
[14:20:04.407] INFO: Found DTB DTB_WZ4QKL
[14:20:04.418] QUIET: Connection to board DTB_WZ4QKL opened.
[14:20:04.421] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[14:20:04.425] INFO: RPC call hashes of host and DTB match: 397073690
[14:20:06.249] INFO: DUT info:
[14:20:06.249] INFO: The DUT currently contains the following objects:
[14:20:06.250] INFO: 2 TBM Cores tbm08c (2 ON)
[14:20:06.250] INFO: TBM Core alpha (0): 7 registers set
[14:20:06.250] INFO: TBM Core beta (1): 7 registers set
[14:20:06.250] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:20:06.250] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.250] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.251] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.251] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.251] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.251] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.251] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.251] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:06.653] INFO: enter 'restricted' command line mode
[14:20:06.653] INFO: enter test to run
[14:20:06.653] INFO: test: highrate no parameter change
[14:20:06.653] INFO: running: highrate
[14:20:06.662] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[14:20:06.896] INFO: ----------------------------------------------------------------------
[14:20:06.896] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:20:06.896] INFO: ----------------------------------------------------------------------
[14:20:07.757] INFO: Expecting 208000 events.
[14:20:31.115] INFO: 208000 events read in total (22827ms).
[14:20:31.129] INFO: Test took 24226ms.
[14:20:31.563] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:32.077] INFO: number of dead pixels (per ROC): 0 0 0 4 2 0 0 0 0 0 0 0 0 0 0 0
[14:20:32.078] INFO: number of red-efficiency pixels: 228 268 229 351 305 368 341 306 354 331 416 332 354 218 214 234
[14:20:32.078] INFO: number of X-ray hits detected: 146675 151785 129141 194170 192063 212417 190208 192568 195486 206743 222672 203501 202349 132046 155033 151444
[14:20:32.078] 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:20:32.078] INFO: number of Vcal hits detected: 207759 207719 207711 207430 207578 207607 207643 207686 207632 207645 207543 207573 207630 207768 207776 207752
[14:20:32.078] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.9 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.9
[14:20:32.078] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.9
[14:20:32.078] INFO: X-ray hit rate [MHz/cm2]: 43.0 44.5 37.9 56.9 56.3 62.3 55.8 56.4 57.3 60.6 65.3 59.6 59.3 38.7 45.4 44.4
[14:20:32.078] INFO: PixTestHighRate::doXPixelAlive() done
[14:20:32.124] INFO: PixTest:: pg_setup set to default.
[14:20:32.175] INFO: enter test to run
[14:20:32.175] INFO: test: exit no parameter change
[14:20:32.242] QUIET: Connection to board 172 closed.
[14:20:32.258] INFO: pXar: this is the end, my friend
pxar.log
[14:20:38.863] INFO: *** Welcome to pxar ***
[14:20:38.863] INFO: *** Today: 2015/09/09
[14:20:38.863] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[14:20:38.865] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[14:20:38.866] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[14:20:38.866] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[14:20:38.950] INFO: clk: 4
[14:20:38.950] INFO: ctr: 4
[14:20:38.950] INFO: sda: 19
[14:20:38.950] INFO: tin: 9
[14:20:38.950] INFO: level: 15
[14:20:38.950] INFO: triggerdelay: 0
[14:20:38.950] QUIET: Instanciating API for pxar 2.5
[14:20:38.950] INFO: Log level: INFO
[14:20:38.960] INFO: Found DTB DTB_WZ4QKL
[14:20:38.972] QUIET: Connection to board DTB_WZ4QKL opened.
[14:20:38.975] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[14:20:38.979] INFO: RPC call hashes of host and DTB match: 397073690
[14:20:40.796] INFO: DUT info:
[14:20:40.796] INFO: The DUT currently contains the following objects:
[14:20:40.796] INFO: 2 TBM Cores tbm08c (2 ON)
[14:20:40.797] INFO: TBM Core alpha (0): 7 registers set
[14:20:40.797] INFO: TBM Core beta (1): 7 registers set
[14:20:40.797] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:20:40.797] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.797] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.798] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.798] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.798] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:40.798] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:41.199] INFO: enter 'restricted' command line mode
[14:20:41.200] INFO: enter test to run
[14:20:41.200] INFO: test: highrate no parameter change
[14:20:41.200] INFO: running: highrate
[14:20:41.209] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[14:20:41.435] INFO: ----------------------------------------------------------------------
[14:20:41.436] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:20:41.436] INFO: ----------------------------------------------------------------------
[14:20:42.297] INFO: Expecting 208000 events.
[14:21:13.767] INFO: 208000 events read in total (30939ms).
[14:21:13.799] INFO: Test took 32356ms.
[14:21:14.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:15.382] INFO: number of dead pixels (per ROC): 0 0 0 4 2 0 0 0 0 0 0 0 0 0 0 0
[14:21:15.382] INFO: number of red-efficiency pixels: 830 828 779 1225 1127 1282 1294 1106 1142 1243 1472 1162 1145 800 701 709
[14:21:15.382] INFO: number of X-ray hits detected: 289308 299814 256133 382055 380088 418134 376426 381121 390387 409815 442679 401296 401961 260965 307741 299789
[14:21:15.382] 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:21:15.382] INFO: number of Vcal hits detected: 207044 207037 206875 206219 206509 206350 206270 206659 206599 206384 205948 206438 206566 206963 207196 207200
[14:21:15.383] INFO: Vcal hit fiducial efficiency (%): 99.6 99.6 99.6 99.3 99.4 99.3 99.3 99.4 99.4 99.3 99.1 99.3 99.4 99.6 99.6 99.7
[14:21:15.383] INFO: Vcal hit overall efficiency (%): 99.5 99.5 99.5 99.1 99.3 99.2 99.2 99.4 99.3 99.2 99.0 99.2 99.3 99.5 99.6 99.6
[14:21:15.383] INFO: X-ray hit rate [MHz/cm2]: 84.8 87.9 75.1 112.0 111.4 122.6 110.3 111.7 114.4 120.1 129.8 117.6 117.8 76.5 90.2 87.9
[14:21:15.383] INFO: PixTestHighRate::doXPixelAlive() done
[14:21:15.430] INFO: PixTest:: pg_setup set to default.
[14:21:15.485] INFO: enter test to run
[14:21:15.485] INFO: test: exit no parameter change
[14:21:15.611] QUIET: Connection to board 172 closed.
[14:21:15.631] INFO: pXar: this is the end, my friend
pxar.log
[14:21:23.396] INFO: *** Welcome to pxar ***
[14:21:23.396] INFO: *** Today: 2015/09/09
[14:21:23.396] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[14:21:23.398] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[14:21:23.399] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[14:21:23.399] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[14:21:23.484] INFO: clk: 4
[14:21:23.484] INFO: ctr: 4
[14:21:23.484] INFO: sda: 19
[14:21:23.484] INFO: tin: 9
[14:21:23.484] INFO: level: 15
[14:21:23.484] INFO: triggerdelay: 0
[14:21:23.484] QUIET: Instanciating API for pxar 2.5
[14:21:23.484] INFO: Log level: INFO
[14:21:23.491] INFO: Found DTB DTB_WZ4QKL
[14:21:23.502] QUIET: Connection to board DTB_WZ4QKL opened.
[14:21:23.505] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[14:21:23.509] INFO: RPC call hashes of host and DTB match: 397073690
[14:21:25.337] INFO: DUT info:
[14:21:25.337] INFO: The DUT currently contains the following objects:
[14:21:25.337] INFO: 2 TBM Cores tbm08c (2 ON)
[14:21:25.337] INFO: TBM Core alpha (0): 7 registers set
[14:21:25.337] INFO: TBM Core beta (1): 7 registers set
[14:21:25.337] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:21:25.338] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.338] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.339] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.339] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:25.740] INFO: enter 'restricted' command line mode
[14:21:25.740] INFO: enter test to run
[14:21:25.741] INFO: test: highrate no parameter change
[14:21:25.741] INFO: running: highrate
[14:21:25.750] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[14:21:25.981] INFO: ----------------------------------------------------------------------
[14:21:25.981] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:21:25.982] INFO: ----------------------------------------------------------------------
[14:21:26.854] INFO: Expecting 208000 events.
[14:21:34.174] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[14:21:34.174] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[14:21:35.420] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (9) != Token Chain Length (8)

[14:21:39.923] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (2) != Token Chain Length (8)

[14:21:39.923] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 3 ROCs were found

[14:21:39.923] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (203) != TBM ID (255)

[14:21:39.924] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (3) != Token Chain Length (8)

[14:21:39.924] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (203) != TBM ID (84)

[14:21:39.924] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (1) != Token Chain Length (8)

[14:21:39.924] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (256) != TBM ID (203)

[14:21:39.924] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (85) != TBM ID (203)

[14:21:39.924] WARNING: Channel 0 ROC 1: Readback start marker after 17 readouts!

[14:21:39.924] WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 0 ROC 4: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[14:21:39.924] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[14:21:43.621] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (6) != Token Chain Length (8)

[14:21:43.622] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[14:21:43.622] WARNING: Channel 0 ROC 7: Readback start marker after 31 readouts!

[14:21:43.622] WARNING: Channel 1 ROC 7: Readback start marker after 31 readouts!

[14:21:44.808] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 0 has NoTokenPass but 5 ROCs were found

[14:21:44.808] ERROR: <datapipe.cc/CheckEventValidity:L469> Channel 1 has NoTokenPass but 4 ROCs were found

[14:21:44.808] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (43) != TBM ID (222)

[14:21:44.808] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (1) != Token Chain Length (8)

[14:21:44.808] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (43) != TBM ID (8)

[14:21:44.808] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 Number of ROCs (1) != Token Chain Length (8)

[14:21:44.812] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (223) != TBM ID (43)

[14:21:44.812] ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (9) != TBM ID (43)

[14:21:44.812] WARNING: Channel 0 ROC 5: Readback start marker after 15 readouts!

[14:21:44.812] WARNING: Channel 0 ROC 6: Readback start marker after 15 readouts!

[14:21:44.812] WARNING: Channel 0 ROC 7: Readback start marker after 15 readouts!

[14:21:44.812] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[14:21:44.812] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[14:21:44.812] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[14:21:44.812] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[14:22:01.757] CRITICAL: <hal.cc/condenseTriggers:L1895> Data size does not correspond to 50 triggers! Aborting data processing!

[14:22:01.787] INFO: 0 events read in total (34402ms).
[14:22:01.831] CRITICAL: <hal.cc/MultiRocAllPixelsCalibrate:L779> Incomplete DAQ data readout! Missing 4160 Events.

[14:22:02.694] INFO: Expecting 208000 events.
[14:22:37.953] INFO: 208000 events read in total (34732ms).
[14:22:37.982] INFO: Test took 36150ms.
[14:22:39.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:40.067] INFO: number of dead pixels (per ROC): 0 0 1 4 2 0 0 0 0 0 0 0 0 0 0 0
[14:22:40.067] INFO: number of red-efficiency pixels: 1919 1751 1503 2540 2373 2645 2585 2431 2523 2577 2958 2551 2403 1564 1542 1584
[14:22:40.067] INFO: number of X-ray hits detected: 431311 445157 379973 566250 565616 624161 560268 566657 581265 608615 656795 598765 597330 387835 457055 445467
[14:22:40.067] 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:22:40.067] INFO: number of Vcal hits detected: 205227 205535 204902 203024 203572 202878 202901 204045 203721 202840 201451 203055 203720 204808 205890 205779
[14:22:40.067] INFO: Vcal hit fiducial efficiency (%): 98.8 98.9 98.8 98.0 98.2 97.8 97.9 98.3 98.1 97.8 97.2 97.9 98.2 98.7 99.1 99.1
[14:22:40.068] INFO: Vcal hit overall efficiency (%): 98.7 98.8 98.5 97.6 97.9 97.5 97.5 98.1 97.9 97.5 96.9 97.6 97.9 98.5 99.0 98.9
[14:22:40.068] INFO: X-ray hit rate [MHz/cm2]: 126.4 130.5 111.4 166.0 165.8 182.9 164.2 166.1 170.4 178.4 192.5 175.5 175.1 113.7 134.0 130.6
[14:22:40.068] INFO: PixTestHighRate::doXPixelAlive() done
[14:22:40.115] INFO: PixTest:: pg_setup set to default.
[14:22:40.164] INFO: enter test to run
[14:22:40.164] INFO: test: exit no parameter change
[14:22:40.241] QUIET: Connection to board 172 closed.
[14:22:40.257] INFO: pXar: this is the end, my friend
pxar.log
[14:22:45.762] INFO: *** Welcome to pxar ***
[14:22:45.762] INFO: *** Today: 2015/09/09
[14:22:45.762] INFO: readRocDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/dacParameters35_C15.dat
[14:22:45.765] INFO: readTbmDacs: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0a.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/tbmParameters_C0b.dat
[14:22:45.765] INFO: readMaskFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/defaultMaskFile.dat
[14:22:45.765] INFO: readTrimFile: /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/trimParameters35_C15.dat
[14:22:45.851] INFO: clk: 4
[14:22:45.852] INFO: ctr: 4
[14:22:45.852] INFO: sda: 19
[14:22:45.852] INFO: tin: 9
[14:22:45.852] INFO: level: 15
[14:22:45.852] INFO: triggerdelay: 0
[14:22:45.852] QUIET: Instanciating API for pxar 2.5
[14:22:45.852] INFO: Log level: INFO
[14:22:45.862] INFO: Found DTB DTB_WZ4QKL
[14:22:45.876] QUIET: Connection to board DTB_WZ4QKL opened.
[14:22:45.880] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 172
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WZ4QKL
MAC address: 40D8551180AC
Hostname: pixelDTB172
Comment:
------------------------------------------------------
[14:22:45.883] INFO: RPC call hashes of host and DTB match: 397073690
[14:22:47.711] INFO: DUT info:
[14:22:47.711] INFO: The DUT currently contains the following objects:
[14:22:47.711] INFO: 2 TBM Cores tbm08c (2 ON)
[14:22:47.711] INFO: TBM Core alpha (0): 7 registers set
[14:22:47.711] INFO: TBM Core beta (1): 7 registers set
[14:22:47.712] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:22:47.712] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.712] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.713] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.713] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:47.713] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:22:48.114] INFO: enter 'restricted' command line mode
[14:22:48.114] INFO: enter test to run
[14:22:48.115] INFO: test: highrate no parameter change
[14:22:48.115] INFO: running: highrate
[14:22:48.124] INFO: readGainPedestalParameters /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C0.dat .. /home/l_tester/XRayTesting/M4553_FullQualification_2015-08-14_15h47m_1439563624/M4553_FullQualification_2015-08-14_15h47m_1439563624/003_Fulltest_p17/phCalibrationFitErr35_C15.dat
[14:22:48.354] INFO: ----------------------------------------------------------------------
[14:22:48.354] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:22:48.354] INFO: ----------------------------------------------------------------------
[14:22:49.225] INFO: Expecting 208000 events.
[14:23:41.282] INFO: 208000 events read in total (51526ms).
[14:23:41.326] INFO: Test took 52964ms.
[14:23:43.037] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:44.141] INFO: number of dead pixels (per ROC): 0 0 0 3 2 0 0 0 0 0 0 0 0 0 0 0
[14:23:44.141] INFO: number of red-efficiency pixels: 3022 2814 2184 3583 3506 3730 3633 3633 3641 3637 3913 3666 3559 2274 2649 2621
[14:23:44.141] INFO: number of X-ray hits detected: 570075 590409 502334 748391 751712 828071 744643 752543 771426 807929 870929 790962 794439 514990 606288 589113
[14:23:44.141] 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:23:44.141] INFO: number of Vcal hits detected: 201753 202534 201056 196621 197726 195593 196125 198216 197794 195438 192874 196225 197651 200661 202945 202825
[14:23:44.141] INFO: Vcal hit fiducial efficiency (%): 97.3 97.6 97.2 95.2 95.7 94.7 95.0 95.7 95.5 94.7 93.4 95.0 95.6 97.0 97.8 97.8
[14:23:44.141] INFO: Vcal hit overall efficiency (%): 97.0 97.4 96.7 94.5 95.1 94.0 94.3 95.3 95.1 94.0 92.7 94.3 95.0 96.5 97.6 97.5
[14:23:44.141] INFO: X-ray hit rate [MHz/cm2]: 167.1 173.1 147.2 219.4 220.3 242.7 218.3 220.6 226.1 236.8 255.3 231.8 232.9 150.9 177.7 172.7
[14:23:44.141] INFO: PixTestHighRate::doXPixelAlive() done
[14:23:44.191] INFO: PixTest:: pg_setup set to default.
[14:23:44.257] INFO: enter test to run
[14:23:44.257] INFO: test: exit no parameter change
[14:23:44.337] QUIET: Connection to board 172 closed.
[14:23:44.354] INFO: pXar: this is the end, my friend
MoReWeb-v0.6.7-73-g24fed82 on branch dev-v0.7.0