[11:33:43.029] <TB3> INFO: *** Welcome to pxar ***
[11:33:43.029] <TB3> INFO: *** Today: 2015/08/25
[11:33:43.029] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C15.dat
[11:33:43.030] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//tbmParameters_C0b.dat
[11:33:43.031] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//defaultMaskFile.dat
[11:33:43.031] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters_C15.dat
[11:33:43.115] <TB3> INFO: clk: 4
[11:33:43.115] <TB3> INFO: ctr: 4
[11:33:43.115] <TB3> INFO: sda: 19
[11:33:43.115] <TB3> INFO: tin: 9
[11:33:43.115] <TB3> INFO: level: 15
[11:33:43.115] <TB3> INFO: triggerdelay: 0
[11:33:43.115] <TB3> QUIET: Instanciating API for pxar prod-01+86~g1838649
[11:33:43.115] <TB3> INFO: Log level: INFO
[11:33:43.123] <TB3> INFO: Found DTB DTB_WZ4I6J
[11:33:43.131] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[11:33:43.134] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[11:33:43.137] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[11:33:44.673] <TB3> INFO: DUT info:
[11:33:44.673] <TB3> INFO: The DUT currently contains the following objects:
[11:33:44.673] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[11:33:44.673] <TB3> INFO: TBM Core alpha (0): 7 registers set
[11:33:44.673] <TB3> INFO: TBM Core beta (1): 7 registers set
[11:33:44.673] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:33:44.673] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:44.673] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:45.075] <TB3> INFO: enter 'restricted' command line mode
[11:33:45.075] <TB3> INFO: enter test to run
[11:33:45.075] <TB3> INFO: test: pretest no parameter change
[11:33:45.075] <TB3> INFO: running: pretest
[11:33:45.081] <TB3> INFO: ######################################################################
[11:33:45.081] <TB3> INFO: PixTestPretest::doTest()
[11:33:45.081] <TB3> INFO: ######################################################################
[11:33:45.083] <TB3> INFO: ----------------------------------------------------------------------
[11:33:45.083] <TB3> INFO: PixTestPretest::programROC()
[11:33:45.083] <TB3> INFO: ----------------------------------------------------------------------
[11:34:03.101] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:34:03.101] <TB3> INFO: IA differences per ROC: 17.7 19.3 20.1 19.3 19.3 17.7 19.3 18.5 18.5 19.3 18.5 19.3 16.9 19.3 20.1 17.7
[11:34:03.190] <TB3> INFO: ----------------------------------------------------------------------
[11:34:03.190] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:34:03.190] <TB3> INFO: ----------------------------------------------------------------------
[11:34:08.375] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 384.3 mA = 24.0187 mA/ROC
[11:34:08.378] <TB3> INFO: ----------------------------------------------------------------------
[11:34:08.378] <TB3> INFO: PixTestPretest::findWorkingPixel()
[11:34:08.378] <TB3> INFO: ----------------------------------------------------------------------
[11:34:16.700] <TB3> INFO: Test took 8316ms.
[11:34:17.007] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:34:17.040] <TB3> INFO: ----------------------------------------------------------------------
[11:34:17.040] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[11:34:17.040] <TB3> INFO: ----------------------------------------------------------------------
[11:34:25.293] <TB3> INFO: Test took 8249ms.
[11:34:25.608] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[11:34:25.608] <TB3> INFO: CalDel: 120 129 156 170 134 122 135 141 132 126 135 143 146 137 143 138
[11:34:25.608] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:34:25.612] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C0.dat
[11:34:25.612] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C1.dat
[11:34:25.613] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C2.dat
[11:34:25.613] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C3.dat
[11:34:25.613] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C4.dat
[11:34:25.613] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C5.dat
[11:34:25.613] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C6.dat
[11:34:25.614] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C7.dat
[11:34:25.614] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C8.dat
[11:34:25.614] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C9.dat
[11:34:25.614] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C10.dat
[11:34:25.614] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C11.dat
[11:34:25.615] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C12.dat
[11:34:25.615] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C13.dat
[11:34:25.615] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C14.dat
[11:34:25.615] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters_C15.dat
[11:34:25.615] <TB3> INFO: write tbm parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//tbmParameters_C0a.dat
[11:34:25.616] <TB3> INFO: write tbm parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//tbmParameters_C0b.dat
[11:34:25.616] <TB3> INFO: PixTestPretest::doTest() done, duration: 40 seconds
[11:34:25.708] <TB3> INFO: enter test to run
[11:34:25.708] <TB3> INFO: test: fulltest no parameter change
[11:34:25.708] <TB3> INFO: running: fulltest
[11:34:25.708] <TB3> INFO: ######################################################################
[11:34:25.708] <TB3> INFO: PixTestFullTest::doTest()
[11:34:25.708] <TB3> INFO: ######################################################################
[11:34:25.709] <TB3> INFO: ######################################################################
[11:34:25.709] <TB3> INFO: PixTestAlive::doTest()
[11:34:25.709] <TB3> INFO: ######################################################################
[11:34:25.711] <TB3> INFO: ----------------------------------------------------------------------
[11:34:25.711] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:34:25.711] <TB3> INFO: ----------------------------------------------------------------------
[11:34:29.160] <TB3> INFO: Test took 3448ms.
[11:34:29.189] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:29.417] <TB3> INFO: PixTestAlive::aliveTest() done
[11:34:29.417] <TB3> INFO: number of dead pixels (per ROC): 2 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[11:34:29.420] <TB3> INFO: ----------------------------------------------------------------------
[11:34:29.420] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:34:29.420] <TB3> INFO: ----------------------------------------------------------------------
[11:34:32.144] <TB3> INFO: Test took 2722ms.
[11:34:32.147] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:32.147] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:34:32.379] <TB3> INFO: PixTestAlive::maskTest() done
[11:34:32.379] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:34:32.381] <TB3> INFO: ----------------------------------------------------------------------
[11:34:32.381] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:34:32.381] <TB3> INFO: ----------------------------------------------------------------------
[11:34:35.812] <TB3> INFO: Test took 3429ms.
[11:34:35.838] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:36.069] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[11:34:36.070] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:34:36.070] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[11:34:36.079] <TB3> INFO: ######################################################################
[11:34:36.079] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:34:36.079] <TB3> INFO: ######################################################################
[11:34:36.082] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[11:34:36.093] <TB3> INFO: dacScan step from 0 .. 29
[11:34:36.093] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:34:36.093] <TB3> INFO: run 1 of 1
[11:34:57.505] <TB3> INFO: Test took 21412ms.
[11:34:57.531] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:57.531] <TB3> INFO: dacScan step from 30 .. 59
[11:34:57.531] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:34:57.531] <TB3> INFO: run 1 of 1
[11:35:21.372] <TB3> INFO: Test took 23841ms.
[11:35:21.499] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:21.515] <TB3> INFO: dacScan step from 60 .. 89
[11:35:21.515] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:35:21.515] <TB3> INFO: run 1 of 1
[11:35:50.537] <TB3> INFO: Test took 29022ms.
[11:35:50.777] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:50.826] <TB3> INFO: dacScan step from 90 .. 119
[11:35:50.826] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:35:50.826] <TB3> INFO: run 1 of 1
[11:36:19.881] <TB3> INFO: Test took 29055ms.
[11:36:20.131] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:20.174] <TB3> INFO: dacScan step from 120 .. 149
[11:36:20.174] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:36:20.174] <TB3> INFO: run 1 of 1
[11:36:44.524] <TB3> INFO: Test took 24350ms.
[11:36:44.730] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:08.990] <TB3> INFO: PixTestBBMap::doTest() done, duration: 152 seconds
[11:37:08.990] <TB3> INFO: number of dead bumps (per ROC): 25 0 2 1 1 0 2 0 0 0 0 1 0 0 0 0
[11:37:08.990] <TB3> INFO: separation cut (per ROC): 82 81 83 76 72 89 81 85 84 95 70 83 84 97 85 84
[11:37:09.064] <TB3> INFO: ######################################################################
[11:37:09.064] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = 4, ntrig/step = 50
[11:37:09.064] <TB3> INFO: ######################################################################
[11:37:09.065] <TB3> INFO: ----------------------------------------------------------------------
[11:37:09.065] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = 4, ntrig/step = 50
[11:37:09.065] <TB3> INFO: ----------------------------------------------------------------------
[11:37:09.065] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4/50) hits flags = 16 (plus default)
[11:37:09.073] <TB3> INFO: dacScan step from 0 .. 3
[11:37:09.073] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:37:09.073] <TB3> INFO: run 1 of 1
[11:37:27.285] <TB3> INFO: Test took 18212ms.
[11:37:27.307] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:27.310] <TB3> INFO: dacScan step from 4 .. 7
[11:37:27.310] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:37:27.310] <TB3> INFO: run 1 of 1
[11:37:46.194] <TB3> INFO: Test took 18883ms.
[11:37:46.217] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:46.220] <TB3> INFO: dacScan step from 8 .. 11
[11:37:46.220] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:37:46.220] <TB3> INFO: run 1 of 1
[11:38:05.169] <TB3> INFO: Test took 18949ms.
[11:38:05.200] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:05.200] <TB3> INFO: dacScan step from 12 .. 15
[11:38:05.200] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:38:05.200] <TB3> INFO: run 1 of 1
[11:38:24.141] <TB3> INFO: Test took 18941ms.
[11:38:24.170] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:24.170] <TB3> INFO: dacScan step from 16 .. 19
[11:38:24.170] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:38:24.170] <TB3> INFO: run 1 of 1
[11:38:43.063] <TB3> INFO: Test took 18893ms.
[11:38:43.093] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:43.093] <TB3> INFO: dacScan step from 20 .. 23
[11:38:43.093] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:38:43.093] <TB3> INFO: run 1 of 1
[11:39:01.998] <TB3> INFO: Test took 18905ms.
[11:39:02.024] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:02.027] <TB3> INFO: dacScan step from 24 .. 27
[11:39:02.027] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:39:02.027] <TB3> INFO: run 1 of 1
[11:39:20.870] <TB3> INFO: Test took 18843ms.
[11:39:20.901] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:20.901] <TB3> INFO: dacScan step from 28 .. 31
[11:39:20.901] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:39:20.901] <TB3> INFO: run 1 of 1
[11:39:39.934] <TB3> INFO: Test took 19033ms.
[11:39:39.964] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:39.964] <TB3> INFO: dacScan step from 32 .. 35
[11:39:39.964] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:39:39.964] <TB3> INFO: run 1 of 1
[11:39:58.945] <TB3> INFO: Test took 18981ms.
[11:39:58.972] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:58.972] <TB3> INFO: dacScan step from 36 .. 39
[11:39:58.972] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:39:58.972] <TB3> INFO: run 1 of 1
[11:40:18.011] <TB3> INFO: Test took 19039ms.
[11:40:18.037] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:18.037] <TB3> INFO: dacScan step from 40 .. 43
[11:40:18.037] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:40:18.038] <TB3> INFO: run 1 of 1
[11:40:36.984] <TB3> INFO: Test took 18946ms.
[11:40:37.007] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:37.007] <TB3> INFO: dacScan step from 44 .. 47
[11:40:37.007] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:40:37.008] <TB3> INFO: run 1 of 1
[11:40:55.962] <TB3> INFO: Test took 18954ms.
[11:40:55.993] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:55.995] <TB3> INFO: dacScan step from 48 .. 51
[11:40:55.995] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:40:55.995] <TB3> INFO: run 1 of 1
[11:41:14.947] <TB3> INFO: Test took 18952ms.
[11:41:14.976] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:14.976] <TB3> INFO: dacScan step from 52 .. 55
[11:41:14.976] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:41:14.976] <TB3> INFO: run 1 of 1
[11:41:33.979] <TB3> INFO: Test took 19003ms.
[11:41:34.008] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:34.008] <TB3> INFO: dacScan step from 56 .. 59
[11:41:34.008] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:41:34.008] <TB3> INFO: run 1 of 1
[11:41:43.723] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:41:43.723] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 12 readouts!
[11:41:43.723] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:41:43.723] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:41:43.723] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:41:43.723] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:41:50.569] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:41:50.569] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[11:41:52.879] <TB3> INFO: Test took 18871ms.
[11:41:52.906] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:52.910] <TB3> INFO: dacScan step from 60 .. 63
[11:41:52.910] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:41:52.910] <TB3> INFO: run 1 of 1
[11:42:11.947] <TB3> INFO: Test took 19037ms.
[11:42:11.983] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:11.983] <TB3> INFO: dacScan step from 64 .. 67
[11:42:11.983] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:42:11.983] <TB3> INFO: run 1 of 1
[11:42:25.586] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:42:25.586] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 11 readouts!
[11:42:25.586] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:42:25.586] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:42:25.586] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:42:25.586] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:42:31.240] <TB3> INFO: Test took 19257ms.
[11:42:31.271] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:31.281] <TB3> INFO: dacScan step from 68 .. 71
[11:42:31.281] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:42:31.281] <TB3> INFO: run 1 of 1
[11:42:51.130] <TB3> INFO: Test took 19849ms.
[11:42:51.184] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:51.185] <TB3> INFO: dacScan step from 72 .. 75
[11:42:51.185] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:42:51.185] <TB3> INFO: run 1 of 1
[11:43:02.851] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (105) != TBM ID (106)
[11:43:02.851] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (105) != TBM ID (106)
[11:43:02.851] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:43:02.851] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:43:05.238] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:43:05.238] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 9 readouts!
[11:43:05.238] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:43:05.238] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:43:05.238] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:43:05.238] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:43:11.530] <TB3> INFO: Test took 20345ms.
[11:43:11.598] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:11.600] <TB3> INFO: dacScan step from 76 .. 79
[11:43:11.600] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:43:11.600] <TB3> INFO: run 1 of 1
[11:43:32.754] <TB3> INFO: Test took 21154ms.
[11:43:32.832] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:32.840] <TB3> INFO: dacScan step from 80 .. 83
[11:43:32.840] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:43:32.840] <TB3> INFO: run 1 of 1
[11:43:55.128] <TB3> INFO: Test took 22287ms.
[11:43:55.230] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:55.236] <TB3> INFO: dacScan step from 84 .. 87
[11:43:55.236] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:43:55.236] <TB3> INFO: run 1 of 1
[11:44:04.714] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 12 readouts!
[11:44:04.714] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:44:04.714] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 12 readouts!
[11:44:04.714] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:44:04.714] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:44:04.714] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:44:04.714] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:44:04.714] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:06.057] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:44:06.057] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 4 readouts!
[11:44:06.057] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:44:06.057] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:44:06.057] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:44:06.057] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:19.075] <TB3> INFO: Test took 23839ms.
[11:44:19.229] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:19.238] <TB3> INFO: dacScan step from 88 .. 91
[11:44:19.238] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:44:19.238] <TB3> INFO: run 1 of 1
[11:44:35.754] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:44:35.755] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:44:35.755] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:36.716] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:44:36.716] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[11:44:36.716] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:44:37.952] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:44:37.953] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:44:37.953] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:44:37.953] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:39.204] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[11:44:42.329] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (5) != TBM ID (6)
[11:44:42.329] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (5) != TBM ID (6)
[11:44:42.329] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:44:42.329] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:44:42.329] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:44:42.329] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:42.329] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[11:44:42.329] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:44:42.329] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:44:44.653] <TB3> INFO: Test took 25415ms.
[11:44:44.845] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:44.853] <TB3> INFO: dacScan step from 92 .. 95
[11:44:44.853] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:44:44.853] <TB3> INFO: run 1 of 1
[11:44:55.950] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:44:55.950] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:44:55.950] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:57.881] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:44:57.881] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[11:44:57.881] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 31 readouts!
[11:44:58.864] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (197) != TBM ID (175)
[11:44:58.864] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:44:58.864] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (197) != TBM ID (198)
[11:44:58.864] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (176) != TBM ID (198)
[11:44:58.864] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:44:58.864] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:44:58.864] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:44:58.864] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:44:58.864] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:45:04.734] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (81) != TBM ID (82)
[11:45:04.734] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (81) != TBM ID (255)
[11:45:04.734] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:45:04.734] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (256) != TBM ID (82)
[11:45:04.735] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:45:04.735] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:45:04.735] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:45:04.735] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:45:04.735] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (163) != TBM ID (164)
[11:45:06.358] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (163) != TBM ID (164)
[11:45:06.358] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:45:06.358] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:45:12.211] <TB3> INFO: Test took 27358ms.
[11:45:12.452] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:12.462] <TB3> INFO: dacScan step from 96 .. 99
[11:45:12.462] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:45:12.462] <TB3> INFO: run 1 of 1
[11:45:27.258] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:45:27.258] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:45:34.047] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:45:34.047] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[11:45:35.392] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:45:35.392] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:45:35.392] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:45:35.392] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:45:40.946] <TB3> INFO: Test took 28484ms.
[11:45:41.169] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:41.177] <TB3> INFO: dacScan step from 100 .. 103
[11:45:41.178] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:45:41.178] <TB3> INFO: run 1 of 1
[11:45:59.065] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (43) != TBM ID (41)
[11:45:59.065] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (43) != TBM ID (42)
[11:45:59.065] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:45:59.065] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (42) != TBM ID (44)
[11:45:59.065] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (43) != TBM ID (44)
[11:45:59.065] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:45:59.903] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:45:59.908] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:45:59.908] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:45:59.908] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:46:09.233] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[11:46:10.168] <TB3> INFO: Test took 28990ms.
[11:46:10.407] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:10.415] <TB3> INFO: dacScan step from 104 .. 107
[11:46:10.415] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:46:10.415] <TB3> INFO: run 1 of 1
[11:46:23.423] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:46:23.423] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:46:23.423] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:46:23.423] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:46:31.851] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:46:31.852] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:46:31.852] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:46:31.852] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:46:38.495] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[11:46:38.495] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[11:46:39.625] <TB3> INFO: Test took 29210ms.
[11:46:39.851] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:39.859] <TB3> INFO: dacScan step from 108 .. 111
[11:46:39.859] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:46:39.859] <TB3> INFO: run 1 of 1
[11:47:06.154] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:47:06.154] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:47:06.154] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:47:06.154] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:47:07.717] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[11:47:07.717] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[11:47:08.888] <TB3> INFO: Test took 29029ms.
[11:47:09.124] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:09.132] <TB3> INFO: dacScan step from 112 .. 115
[11:47:09.132] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:47:09.132] <TB3> INFO: run 1 of 1
[11:47:18.006] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (205) != TBM ID (206)
[11:47:18.006] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (205) != TBM ID (206)
[11:47:18.006] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:47:18.006] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:47:18.852] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:47:18.852] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:47:18.852] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:47:18.852] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:47:37.165] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[11:47:37.165] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[11:47:38.457] <TB3> INFO: Test took 29325ms.
[11:47:38.687] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:38.696] <TB3> INFO: dacScan step from 116 .. 119
[11:47:38.696] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:47:38.696] <TB3> INFO: run 1 of 1
[11:47:50.925] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (1) != Token Chain Length (4)
[11:47:50.926] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:47:50.926] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (26) != TBM ID (144)
[11:47:50.926] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (1) != Token Chain Length (4)
[11:47:50.926] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (145) != TBM ID (26)
[11:47:50.926] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:47:50.926] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[11:47:50.926] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:47:50.926] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:48:06.586] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[11:48:07.873] <TB3> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[11:48:33.048] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:48:33.049] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:48:33.049] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:48:35.839] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[11:48:35.839] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[11:48:36.408] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:48:36.409] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:48:36.409] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:48:36.409] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:48:36.678] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:48:36.678] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:48:36.678] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:48:36.678] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:48:37.109] <TB3> INFO: Test took 29186ms.
[11:48:37.341] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:37.350] <TB3> INFO: dacScan step from 120 .. 123
[11:48:37.350] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:48:37.350] <TB3> INFO: run 1 of 1
[11:49:06.400] <TB3> INFO: Test took 29050ms.
[11:49:06.628] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:06.637] <TB3> INFO: dacScan step from 124 .. 127
[11:49:06.637] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:49:06.637] <TB3> INFO: run 1 of 1
[11:49:14.449] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:49:14.449] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:49:14.449] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:49:14.987] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:49:14.987] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:49:14.987] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:49:14.987] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:49:18.531] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:49:18.531] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:49:18.531] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 31 readouts!
[11:49:18.531] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 31 readouts!
[11:49:34.561] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (196) != TBM ID (8)
[11:49:34.561] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[11:49:34.561] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (9) != TBM ID (197)
[11:49:35.763] <TB3> INFO: Test took 29126ms.
[11:49:35.983] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:35.991] <TB3> INFO: dacScan step from 128 .. 131
[11:49:35.991] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:49:35.991] <TB3> INFO: run 1 of 1
[11:49:53.256] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:49:53.257] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:49:53.257] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:50:01.297] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[11:50:05.044] <TB3> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[11:50:12.797] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:50:12.797] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:50:31.880] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:50:31.881] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:50:31.881] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:50:34.205] <TB3> INFO: Test took 29110ms.
[11:50:34.425] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:34.433] <TB3> INFO: dacScan step from 132 .. 135
[11:50:34.433] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:50:34.433] <TB3> INFO: run 1 of 1
[11:51:03.694] <TB3> INFO: Test took 29261ms.
[11:51:03.936] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:03.948] <TB3> INFO: dacScan step from 136 .. 139
[11:51:03.949] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:51:03.949] <TB3> INFO: run 1 of 1
[11:51:14.143] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[11:51:14.437] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 13 readouts!
[11:51:14.437] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 3 readouts!
[11:51:14.437] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 3 readouts!
[11:51:27.113] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[11:51:30.178] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:51:30.178] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:51:30.178] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:51:33.395] <TB3> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -2 Events.
[11:51:43.672] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:51:43.672] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[11:52:02.632] <TB3> INFO: Test took 29185ms.
[11:52:02.857] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:02.865] <TB3> INFO: dacScan step from 140 .. 143
[11:52:02.865] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:52:02.865] <TB3> INFO: run 1 of 1
[11:52:24.168] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:52:24.168] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:52:24.168] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:52:24.168] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:52:24.636] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:52:24.636] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:52:24.636] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (36) != TBM ID (50)
[11:52:24.636] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (1) != Token Chain Length (4)
[11:52:24.636] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (51) != TBM ID (36)
[11:52:24.636] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:52:24.636] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:52:24.636] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:52:30.541] <TB3> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[11:52:40.686] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (150) != TBM ID (60)
[11:52:40.686] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (150) != TBM ID (151)
[11:52:40.686] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (61) != TBM ID (151)
[11:52:40.686] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:52:40.686] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:52:40.686] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:52:40.686] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:52:44.194] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[11:52:56.799] <TB3> INFO: Test took 26207ms.
[11:52:57.184] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:57.199] <TB3> INFO: dacScan step from 144 .. 147
[11:52:57.199] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:52:57.199] <TB3> INFO: run 1 of 1
[11:53:11.266] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 8 readouts!
[11:53:11.266] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:53:11.266] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:53:11.266] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:53:24.985] <TB3> INFO: Test took 27786ms.
[11:53:25.222] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:25.231] <TB3> INFO: dacScan step from 148 .. 149
[11:53:25.231] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:53:25.231] <TB3> INFO: run 1 of 1
[11:53:39.657] <TB3> INFO: Test took 14426ms.
[11:53:39.765] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:39.771] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:41.213] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:42.692] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:44.064] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:45.690] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:47.262] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:48.739] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:50.258] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:51.666] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:53.009] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:54.348] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:55.786] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:57.173] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:58.533] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:53:59.871] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:54:01.212] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:54:02.595] <TB3> INFO: PixTestScurves::scurves() done
[11:54:02.595] <TB3> INFO: Vcal mean: 88.56 90.10 88.46 69.22 87.58 94.72 80.58 88.99 93.88 96.14 73.95 89.77 86.87 94.80 91.03 88.25
[11:54:02.595] <TB3> INFO: Vcal RMS: 5.86 5.30 5.62 4.73 5.28 5.70 5.52 6.26 5.53 5.14 4.33 6.04 6.01 5.72 6.25 5.62
[11:54:02.595] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1013 seconds
[11:54:02.682] <TB3> INFO: ######################################################################
[11:54:02.682] <TB3> INFO: PixTestTrim::doTest()
[11:54:02.682] <TB3> INFO: ######################################################################
[11:54:02.684] <TB3> INFO: ----------------------------------------------------------------------
[11:54:02.684] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[11:54:02.684] <TB3> INFO: ----------------------------------------------------------------------
[11:54:02.789] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:54:02.789] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[11:54:02.798] <TB3> INFO: dacScan step from 0 .. 19
[11:54:02.798] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:54:02.798] <TB3> INFO: run 1 of 1
[11:54:17.329] <TB3> INFO: Test took 14531ms.
[11:54:17.355] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:17.355] <TB3> INFO: dacScan step from 20 .. 39
[11:54:17.355] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:54:17.355] <TB3> INFO: run 1 of 1
[11:54:31.895] <TB3> INFO: Test took 14540ms.
[11:54:31.915] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:31.915] <TB3> INFO: dacScan step from 40 .. 59
[11:54:31.915] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:54:31.915] <TB3> INFO: run 1 of 1
[11:54:46.267] <TB3> INFO: Test took 14351ms.
[11:54:46.289] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:46.289] <TB3> INFO: dacScan step from 60 .. 79
[11:54:46.289] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:54:46.289] <TB3> INFO: run 1 of 1
[11:54:58.094] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (69) != TBM ID (70)
[11:54:58.094] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (69) != TBM ID (70)
[11:54:58.094] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:54:58.094] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:55:00.715] <TB3> INFO: Test took 14426ms.
[11:55:00.739] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:00.739] <TB3> INFO: dacScan step from 80 .. 99
[11:55:00.739] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:55:00.740] <TB3> INFO: run 1 of 1
[11:55:15.958] <TB3> INFO: Test took 15218ms.
[11:55:16.035] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:16.049] <TB3> INFO: dacScan step from 100 .. 119
[11:55:16.049] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:55:16.049] <TB3> INFO: run 1 of 1
[11:55:33.925] <TB3> INFO: Test took 17876ms.
[11:55:34.071] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:34.098] <TB3> INFO: dacScan step from 120 .. 139
[11:55:34.098] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:55:34.098] <TB3> INFO: run 1 of 1
[11:55:52.666] <TB3> INFO: Test took 18568ms.
[11:55:52.820] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:52.844] <TB3> INFO: dacScan step from 140 .. 159
[11:55:52.844] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:55:52.844] <TB3> INFO: run 1 of 1
[11:56:08.264] <TB3> INFO: Test took 15420ms.
[11:56:08.335] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:29.945] <TB3> INFO: ROC 0 VthrComp = 96
[11:56:29.946] <TB3> INFO: ROC 1 VthrComp = 98
[11:56:29.946] <TB3> INFO: ROC 2 VthrComp = 94
[11:56:29.946] <TB3> INFO: ROC 3 VthrComp = 74
[11:56:29.946] <TB3> INFO: ROC 4 VthrComp = 93
[11:56:29.946] <TB3> INFO: ROC 5 VthrComp = 97
[11:56:29.946] <TB3> INFO: ROC 6 VthrComp = 83
[11:56:29.946] <TB3> INFO: ROC 7 VthrComp = 89
[11:56:29.946] <TB3> INFO: ROC 8 VthrComp = 98
[11:56:29.946] <TB3> INFO: ROC 9 VthrComp = 101
[11:56:29.946] <TB3> INFO: ROC 10 VthrComp = 81
[11:56:29.947] <TB3> INFO: ROC 11 VthrComp = 92
[11:56:29.947] <TB3> INFO: ROC 12 VthrComp = 86
[11:56:29.947] <TB3> INFO: ROC 13 VthrComp = 99
[11:56:29.947] <TB3> INFO: ROC 14 VthrComp = 94
[11:56:29.947] <TB3> INFO: ROC 15 VthrComp = 91
[11:56:29.947] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:56:29.947] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[11:56:29.956] <TB3> INFO: dacScan step from 0 .. 19
[11:56:29.956] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:56:29.956] <TB3> INFO: run 1 of 1
[11:56:45.093] <TB3> INFO: Test took 15137ms.
[11:56:45.120] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:45.120] <TB3> INFO: dacScan step from 20 .. 39
[11:56:45.120] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:56:45.120] <TB3> INFO: run 1 of 1
[11:57:00.257] <TB3> INFO: Test took 15137ms.
[11:57:00.295] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:00.299] <TB3> INFO: dacScan step from 40 .. 59
[11:57:00.299] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:57:00.299] <TB3> INFO: run 1 of 1
[11:57:18.996] <TB3> INFO: Test took 18697ms.
[11:57:19.152] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:19.178] <TB3> INFO: dacScan step from 60 .. 79
[11:57:19.178] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:57:19.178] <TB3> INFO: run 1 of 1
[11:57:39.274] <TB3> INFO: Test took 20096ms.
[11:57:39.446] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:39.476] <TB3> INFO: dacScan step from 80 .. 99
[11:57:39.476] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:57:39.476] <TB3> INFO: run 1 of 1
[11:57:59.686] <TB3> INFO: Test took 20210ms.
[11:57:59.864] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:59.893] <TB3> INFO: dacScan step from 100 .. 119
[11:57:59.893] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:57:59.893] <TB3> INFO: run 1 of 1
[11:58:19.652] <TB3> INFO: Test took 19759ms.
[11:58:19.818] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:19.849] <TB3> INFO: dacScan step from 120 .. 139
[11:58:19.849] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:58:19.850] <TB3> INFO: run 1 of 1
[11:58:38.833] <TB3> INFO: Test took 18983ms.
[11:58:39.088] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:39.119] <TB3> INFO: dacScan step from 140 .. 159
[11:58:39.119] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:58:39.119] <TB3> INFO: run 1 of 1
[11:58:57.852] <TB3> INFO: Test took 18732ms.
[11:58:58.028] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:24.033] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 58.1267 for pixel 49/79 mean/min/max = 44.5992/31.06/58.1384
[11:59:24.033] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 57.1841 for pixel 5/8 mean/min/max = 44.2312/31.1608/57.3016
[11:59:24.033] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 58.2058 for pixel 1/79 mean/min/max = 44.7604/31.2971/58.2237
[11:59:24.033] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 56.562 for pixel 51/26 mean/min/max = 45.8139/34.7509/56.8768
[11:59:24.034] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 59.2994 for pixel 18/1 mean/min/max = 45.7797/32.2379/59.3214
[11:59:24.034] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 60.2914 for pixel 0/77 mean/min/max = 46.0657/31.6724/60.4589
[11:59:24.034] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 60.9102 for pixel 11/79 mean/min/max = 46.3222/31.7226/60.9219
[11:59:24.034] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 63.0349 for pixel 0/2 mean/min/max = 47.2701/31.5021/63.0381
[11:59:24.035] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 59.7026 for pixel 8/74 mean/min/max = 45.4889/31.2236/59.7542
[11:59:24.035] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 59.5949 for pixel 51/31 mean/min/max = 46.0268/32.2581/59.7955
[11:59:24.036] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 55.5122 for pixel 8/48 mean/min/max = 43.8514/32.0758/55.6271
[11:59:24.036] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 61.4413 for pixel 5/25 mean/min/max = 46.4845/31.4361/61.533
[11:59:24.036] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 61.873 for pixel 12/37 mean/min/max = 46.6816/31.3937/61.9695
[11:59:24.037] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 61.1558 for pixel 36/79 mean/min/max = 46.0888/30.997/61.1805
[11:59:24.037] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 61.508 for pixel 0/25 mean/min/max = 46.3521/30.8374/61.8669
[11:59:24.037] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 59.7852 for pixel 0/66 mean/min/max = 46.0083/32.2104/59.8062
[11:59:24.038] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:59:27.382] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 4 readouts!
[11:59:27.382] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 4 readouts!
[11:59:27.382] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 12 readouts!
[11:59:27.382] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 12 readouts!
[11:59:47.486] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[11:59:47.486] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[11:59:47.486] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[11:59:47.486] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:00:59.130] <TB3> INFO: Test took 95093ms.
[12:01:00.555] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[12:01:00.564] <TB3> INFO: dacScan step from 0 .. 19
[12:01:00.564] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:01:00.564] <TB3> INFO: run 1 of 2
[12:01:15.608] <TB3> INFO: Test took 15044ms.
[12:01:15.641] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:15.643] <TB3> INFO: run 2 of 2
[12:01:30.704] <TB3> INFO: Test took 15061ms.
[12:01:30.743] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:30.745] <TB3> INFO: dacScan step from 20 .. 39
[12:01:30.745] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:01:30.745] <TB3> INFO: run 1 of 2
[12:01:48.829] <TB3> INFO: Test took 18083ms.
[12:01:48.978] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:49.007] <TB3> INFO: run 2 of 2
[12:02:06.917] <TB3> INFO: Test took 17910ms.
[12:02:07.076] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:07.103] <TB3> INFO: dacScan step from 40 .. 59
[12:02:07.103] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:02:07.103] <TB3> INFO: run 1 of 2
[12:02:27.226] <TB3> INFO: Test took 20123ms.
[12:02:27.397] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:27.427] <TB3> INFO: run 2 of 2
[12:02:47.677] <TB3> INFO: Test took 20249ms.
[12:02:47.848] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:47.877] <TB3> INFO: dacScan step from 60 .. 79
[12:02:47.877] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:02:47.877] <TB3> INFO: run 1 of 2
[12:03:03.465] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:03:03.466] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:03:03.466] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:03:03.466] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:03:07.893] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:03:07.893] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[12:03:08.178] <TB3> INFO: Test took 20302ms.
[12:03:08.346] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:08.399] <TB3> INFO: run 2 of 2
[12:03:28.762] <TB3> INFO: Test took 20362ms.
[12:03:29.008] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:29.104] <TB3> INFO: dacScan step from 80 .. 99
[12:03:29.104] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:03:29.104] <TB3> INFO: run 1 of 2
[12:03:49.422] <TB3> INFO: Test took 20318ms.
[12:03:49.593] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:49.641] <TB3> INFO: run 2 of 2
[12:04:09.995] <TB3> INFO: Test took 20354ms.
[12:04:10.156] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:10.185] <TB3> INFO: dacScan step from 100 .. 119
[12:04:10.185] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:04:10.185] <TB3> INFO: run 1 of 2
[12:04:30.520] <TB3> INFO: Test took 20335ms.
[12:04:30.696] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:30.751] <TB3> INFO: run 2 of 2
[12:04:51.070] <TB3> INFO: Test took 20319ms.
[12:04:51.240] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:51.292] <TB3> INFO: dacScan step from 120 .. 139
[12:04:51.292] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:04:51.292] <TB3> INFO: run 1 of 2
[12:05:11.405] <TB3> INFO: Test took 20113ms.
[12:05:11.574] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:11.611] <TB3> INFO: run 2 of 2
[12:05:23.808] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (75) != TBM ID (76)
[12:05:23.808] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (75) != TBM ID (76)
[12:05:23.808] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:05:23.808] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:05:31.813] <TB3> INFO: Test took 20202ms.
[12:05:31.988] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:32.031] <TB3> INFO: dacScan step from 140 .. 159
[12:05:32.031] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:05:32.031] <TB3> INFO: run 1 of 2
[12:05:52.206] <TB3> INFO: Test took 20175ms.
[12:05:52.372] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:52.416] <TB3> INFO: run 2 of 2
[12:06:12.598] <TB3> INFO: Test took 20182ms.
[12:06:12.772] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:12.803] <TB3> INFO: dacScan step from 160 .. 179
[12:06:12.803] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:06:12.803] <TB3> INFO: run 1 of 2
[12:06:33.166] <TB3> INFO: Test took 20363ms.
[12:06:33.341] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:33.373] <TB3> INFO: run 2 of 2
[12:06:53.918] <TB3> INFO: Test took 20545ms.
[12:06:54.077] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:54.107] <TB3> INFO: dacScan step from 180 .. 199
[12:06:54.107] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:06:54.107] <TB3> INFO: run 1 of 2
[12:07:15.374] <TB3> INFO: Test took 21267ms.
[12:07:15.551] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:15.584] <TB3> INFO: run 2 of 2
[12:07:35.178] <TB3> INFO: Test took 19594ms.
[12:07:35.337] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:00.209] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.020561 .. 255.000000
[12:08:00.307] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[12:08:00.316] <TB3> INFO: dacScan step from 0 .. 19
[12:08:00.316] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:08:00.316] <TB3> INFO: run 1 of 1
[12:08:13.996] <TB3> INFO: Test took 13680ms.
[12:08:14.020] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:14.020] <TB3> INFO: dacScan step from 20 .. 39
[12:08:14.020] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:08:14.020] <TB3> INFO: run 1 of 1
[12:08:28.068] <TB3> INFO: Test took 14048ms.
[12:08:28.150] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:28.169] <TB3> INFO: dacScan step from 40 .. 59
[12:08:28.169] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:08:28.169] <TB3> INFO: run 1 of 1
[12:08:44.597] <TB3> INFO: Test took 16428ms.
[12:08:44.753] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:44.787] <TB3> INFO: dacScan step from 60 .. 79
[12:08:44.787] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:08:44.787] <TB3> INFO: run 1 of 1
[12:09:02.445] <TB3> INFO: Test took 17658ms.
[12:09:02.613] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:02.654] <TB3> INFO: dacScan step from 80 .. 99
[12:09:02.654] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:09:02.654] <TB3> INFO: run 1 of 1
[12:09:20.319] <TB3> INFO: Test took 17665ms.
[12:09:20.464] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:20.506] <TB3> INFO: dacScan step from 100 .. 119
[12:09:20.506] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:09:20.506] <TB3> INFO: run 1 of 1
[12:09:38.075] <TB3> INFO: Test took 17569ms.
[12:09:38.216] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:38.245] <TB3> INFO: dacScan step from 120 .. 139
[12:09:38.245] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:09:38.245] <TB3> INFO: run 1 of 1
[12:09:55.764] <TB3> INFO: Test took 17520ms.
[12:09:55.900] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:55.929] <TB3> INFO: dacScan step from 140 .. 159
[12:09:55.929] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:09:55.929] <TB3> INFO: run 1 of 1
[12:10:13.570] <TB3> INFO: Test took 17641ms.
[12:10:13.726] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:13.753] <TB3> INFO: dacScan step from 160 .. 179
[12:10:13.753] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:10:13.753] <TB3> INFO: run 1 of 1
[12:10:31.522] <TB3> INFO: Test took 17769ms.
[12:10:31.682] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:31.714] <TB3> INFO: dacScan step from 180 .. 199
[12:10:31.714] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:10:31.714] <TB3> INFO: run 1 of 1
[12:10:50.226] <TB3> INFO: Test took 18511ms.
[12:10:50.392] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:50.437] <TB3> INFO: dacScan step from 200 .. 219
[12:10:50.437] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:10:50.437] <TB3> INFO: run 1 of 1
[12:11:08.154] <TB3> INFO: Test took 17717ms.
[12:11:08.295] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:08.324] <TB3> INFO: dacScan step from 220 .. 239
[12:11:08.324] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:11:08.324] <TB3> INFO: run 1 of 1
[12:11:26.000] <TB3> INFO: Test took 17676ms.
[12:11:26.138] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:26.167] <TB3> INFO: dacScan step from 240 .. 255
[12:11:26.167] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:11:26.167] <TB3> INFO: run 1 of 1
[12:11:40.830] <TB3> INFO: Test took 14663ms.
[12:11:40.939] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:14.123] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 13.658943 .. 67.964248
[12:12:14.211] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 77 (20/-1) hits flags = 16 (plus default)
[12:12:14.219] <TB3> INFO: dacScan step from 3 .. 22
[12:12:14.219] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:12:14.219] <TB3> INFO: run 1 of 1
[12:12:27.407] <TB3> INFO: Test took 13188ms.
[12:12:27.431] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:27.431] <TB3> INFO: dacScan step from 23 .. 42
[12:12:27.431] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:12:27.431] <TB3> INFO: run 1 of 1
[12:12:42.153] <TB3> INFO: Test took 14722ms.
[12:12:42.291] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:42.328] <TB3> INFO: dacScan step from 43 .. 62
[12:12:42.328] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:12:42.328] <TB3> INFO: run 1 of 1
[12:12:59.055] <TB3> INFO: Test took 16727ms.
[12:12:59.212] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:59.251] <TB3> INFO: dacScan step from 63 .. 77
[12:12:59.251] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:12:59.251] <TB3> INFO: run 1 of 1
[12:13:12.468] <TB3> INFO: Test took 13217ms.
[12:13:12.580] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:32.557] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 2.852142 .. 67.964248
[12:13:32.646] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 77 (20/-1) hits flags = 16 (plus default)
[12:13:32.655] <TB3> INFO: dacScan step from 2 .. 21
[12:13:32.655] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:13:32.655] <TB3> INFO: run 1 of 1
[12:13:45.621] <TB3> INFO: Test took 12966ms.
[12:13:45.644] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:45.644] <TB3> INFO: dacScan step from 22 .. 41
[12:13:45.644] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:13:45.644] <TB3> INFO: run 1 of 1
[12:13:59.866] <TB3> INFO: Test took 14221ms.
[12:13:59.950] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:59.968] <TB3> INFO: dacScan step from 42 .. 61
[12:13:59.968] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:13:59.968] <TB3> INFO: run 1 of 1
[12:14:16.546] <TB3> INFO: Test took 16578ms.
[12:14:16.772] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:16.825] <TB3> INFO: dacScan step from 62 .. 77
[12:14:16.825] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:14:16.825] <TB3> INFO: run 1 of 1
[12:14:31.072] <TB3> INFO: Test took 14247ms.
[12:14:31.180] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:50.441] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 0.500000 .. 67.964248
[12:14:50.520] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 77 (20/-1) hits flags = 16 (plus default)
[12:14:50.528] <TB3> INFO: dacScan step from 0 .. 19
[12:14:50.528] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:14:50.528] <TB3> INFO: run 1 of 1
[12:15:03.826] <TB3> INFO: Test took 13298ms.
[12:15:03.844] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:03.844] <TB3> INFO: dacScan step from 20 .. 39
[12:15:03.844] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:15:03.844] <TB3> INFO: run 1 of 1
[12:15:18.040] <TB3> INFO: Test took 14196ms.
[12:15:18.137] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:18.159] <TB3> INFO: dacScan step from 40 .. 59
[12:15:18.159] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:15:18.159] <TB3> INFO: run 1 of 1
[12:15:34.999] <TB3> INFO: Test took 16839ms.
[12:15:35.153] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:35.187] <TB3> INFO: dacScan step from 60 .. 77
[12:15:35.187] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[12:15:35.187] <TB3> INFO: run 1 of 1
[12:15:51.362] <TB3> INFO: Test took 16175ms.
[12:15:51.494] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:11.512] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:16:11.512] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[12:16:11.520] <TB3> INFO: dacScan step from 15 .. 34
[12:16:11.520] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:16:11.520] <TB3> INFO: run 1 of 2
[12:16:26.265] <TB3> INFO: Test took 14745ms.
[12:16:26.301] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:26.308] <TB3> INFO: run 2 of 2
[12:16:40.955] <TB3> INFO: Test took 14647ms.
[12:16:40.991] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:40.999] <TB3> INFO: dacScan step from 35 .. 54
[12:16:40.999] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:16:40.999] <TB3> INFO: run 1 of 2
[12:16:59.810] <TB3> INFO: Test took 18811ms.
[12:16:59.986] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:00.017] <TB3> INFO: run 2 of 2
[12:17:20.075] <TB3> INFO: Test took 20058ms.
[12:17:20.264] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:20.299] <TB3> INFO: dacScan step from 55 .. 55
[12:17:20.299] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:17:20.299] <TB3> INFO: run 1 of 2
[12:17:24.018] <TB3> INFO: Test took 3719ms.
[12:17:24.031] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:24.034] <TB3> INFO: run 2 of 2
[12:17:27.764] <TB3> INFO: Test took 3730ms.
[12:17:27.780] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:41.504] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:17:41.504] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:17:41.504] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:17:41.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:17:41.506] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:17:41.506] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:17:41.506] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:17:41.506] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:17:41.506] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:17:41.506] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:17:41.507] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:17:41.518] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:17:41.524] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:17:41.531] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:17:41.537] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:17:41.544] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:17:41.551] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:17:41.558] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:17:41.565] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:17:41.571] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:17:41.578] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:17:41.585] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:17:41.591] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:17:41.598] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:17:41.605] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:17:41.612] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:17:41.618] <TB3> INFO: PixTestTrim::trimTest() done
[12:17:41.618] <TB3> INFO: vtrim: 113 117 104 82 102 124 117 115 110 108 106 196 113 123 112 111
[12:17:41.618] <TB3> INFO: vthrcomp: 96 98 94 74 93 97 83 89 98 101 81 92 86 99 94 91
[12:17:41.618] <TB3> INFO: vcal mean: 35.04 34.99 35.06 35.04 35.01 35.06 35.06 35.04 35.02 35.07 35.11 34.96 34.99 35.06 35.01 35.01
[12:17:41.618] <TB3> INFO: vcal RMS: 1.13 1.09 1.08 1.07 1.11 1.07 1.03 1.03 1.17 0.97 0.94 2.29 1.23 1.06 1.02 1.01
[12:17:41.618] <TB3> INFO: bits mean: 10.13 10.43 10.43 7.87 9.59 9.75 9.73 9.11 9.98 9.04 10.42 11.57 9.55 10.08 9.47 9.42
[12:17:41.618] <TB3> INFO: bits RMS: 2.55 2.40 2.37 2.86 2.66 2.58 2.57 2.80 2.60 2.82 2.30 1.71 2.70 2.48 2.80 2.71
[12:17:41.626] <TB3> INFO: ----------------------------------------------------------------------
[12:17:41.626] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:17:41.626] <TB3> INFO: ----------------------------------------------------------------------
[12:17:41.629] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[12:17:41.638] <TB3> INFO: dacScan step from 0 .. 19
[12:17:41.638] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:17:41.638] <TB3> INFO: run 1 of 2
[12:17:56.780] <TB3> INFO: Test took 15142ms.
[12:17:56.804] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:56.804] <TB3> INFO: run 2 of 2
[12:18:11.224] <TB3> INFO: Test took 14420ms.
[12:18:11.251] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:11.251] <TB3> INFO: dacScan step from 20 .. 39
[12:18:11.251] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:18:11.251] <TB3> INFO: run 1 of 2
[12:18:26.375] <TB3> INFO: Test took 15124ms.
[12:18:26.397] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:26.397] <TB3> INFO: run 2 of 2
[12:18:40.912] <TB3> INFO: Test took 14515ms.
[12:18:40.932] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:40.932] <TB3> INFO: dacScan step from 40 .. 59
[12:18:40.932] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:18:40.932] <TB3> INFO: run 1 of 2
[12:18:56.055] <TB3> INFO: Test took 15123ms.
[12:18:56.079] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:56.079] <TB3> INFO: run 2 of 2
[12:19:11.125] <TB3> INFO: Test took 15046ms.
[12:19:11.146] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:11.146] <TB3> INFO: dacScan step from 60 .. 79
[12:19:11.146] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:19:11.146] <TB3> INFO: run 1 of 2
[12:19:26.263] <TB3> INFO: Test took 15117ms.
[12:19:26.284] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:26.284] <TB3> INFO: run 2 of 2
[12:19:41.403] <TB3> INFO: Test took 15119ms.
[12:19:41.430] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:41.430] <TB3> INFO: dacScan step from 80 .. 99
[12:19:41.430] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:19:41.430] <TB3> INFO: run 1 of 2
[12:19:52.050] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:19:52.050] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:19:52.050] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:19:56.987] <TB3> INFO: Test took 15557ms.
[12:19:57.024] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:57.027] <TB3> INFO: run 2 of 2
[12:20:09.412] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:20:09.412] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:20:09.412] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:20:09.412] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:20:12.480] <TB3> INFO: Test took 15453ms.
[12:20:12.521] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:12.524] <TB3> INFO: dacScan step from 100 .. 119
[12:20:12.524] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:20:12.524] <TB3> INFO: run 1 of 2
[12:20:30.055] <TB3> INFO: Test took 17531ms.
[12:20:30.163] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:30.180] <TB3> INFO: run 2 of 2
[12:20:47.781] <TB3> INFO: Test took 17601ms.
[12:20:47.903] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:47.921] <TB3> INFO: dacScan step from 120 .. 139
[12:20:47.921] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:20:47.921] <TB3> INFO: run 1 of 2
[12:21:08.009] <TB3> INFO: Test took 20088ms.
[12:21:08.175] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:08.204] <TB3> INFO: run 2 of 2
[12:21:20.008] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:21:20.008] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:21:20.008] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (2) != TBM ID (8)
[12:21:20.008] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:21:20.008] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (9) != TBM ID (2)
[12:21:20.008] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:21:20.008] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:21:28.191] <TB3> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[12:21:48.181] <TB3> INFO: Test took 19955ms.
[12:21:48.347] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:48.375] <TB3> INFO: dacScan step from 140 .. 159
[12:21:48.375] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:21:48.375] <TB3> INFO: run 1 of 2
[12:22:02.058] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (122) != TBM ID (189)
[12:22:02.058] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (122) != TBM ID (123)
[12:22:02.058] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (190) != TBM ID (123)
[12:22:02.058] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:22:02.058] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:22:02.058] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:22:02.058] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:22:08.444] <TB3> INFO: Test took 20069ms.
[12:22:08.614] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:08.643] <TB3> INFO: run 2 of 2
[12:22:20.273] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 14 readouts!
[12:22:20.273] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:22:20.273] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 14 readouts!
[12:22:20.274] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:22:20.274] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:22:20.274] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:22:20.274] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:22:20.274] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:22:28.780] <TB3> INFO: Test took 20137ms.
[12:22:28.942] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:28.970] <TB3> INFO: dacScan step from 160 .. 179
[12:22:28.970] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:22:28.970] <TB3> INFO: run 1 of 2
[12:22:49.136] <TB3> INFO: Test took 20165ms.
[12:22:49.294] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:49.322] <TB3> INFO: run 2 of 2
[12:23:08.160] <TB3> INFO: Test took 18838ms.
[12:23:08.319] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:08.350] <TB3> INFO: dacScan step from 180 .. 199
[12:23:08.350] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:23:08.350] <TB3> INFO: run 1 of 2
[12:23:26.102] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 8 readouts!
[12:23:26.102] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 8 readouts!
[12:23:28.041] <TB3> INFO: Test took 19691ms.
[12:23:28.236] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:28.272] <TB3> INFO: run 2 of 2
[12:23:45.925] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:23:45.925] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:23:45.925] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (251) != TBM ID (252)
[12:23:45.925] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:23:45.925] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:23:45.925] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:23:45.925] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:23:49.248] <TB3> INFO: Test took 20976ms.
[12:23:49.412] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:18.819] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 168 (20/5) hits flags = 16 (plus default)
[12:24:18.828] <TB3> INFO: dacScan step from 0 .. 19
[12:24:18.828] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:24:18.828] <TB3> INFO: run 1 of 2
[12:24:33.176] <TB3> INFO: Test took 14348ms.
[12:24:33.198] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:33.198] <TB3> INFO: run 2 of 2
[12:24:47.631] <TB3> INFO: Test took 14433ms.
[12:24:47.659] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:47.659] <TB3> INFO: dacScan step from 20 .. 39
[12:24:47.659] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:24:47.659] <TB3> INFO: run 1 of 2
[12:25:01.956] <TB3> INFO: Test took 14297ms.
[12:25:01.977] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:01.977] <TB3> INFO: run 2 of 2
[12:25:16.479] <TB3> INFO: Test took 14502ms.
[12:25:16.507] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:16.507] <TB3> INFO: dacScan step from 40 .. 59
[12:25:16.507] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:25:16.507] <TB3> INFO: run 1 of 2
[12:25:31.180] <TB3> INFO: Test took 14673ms.
[12:25:31.203] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:31.203] <TB3> INFO: run 2 of 2
[12:25:46.234] <TB3> INFO: Test took 15030ms.
[12:25:46.261] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:46.261] <TB3> INFO: dacScan step from 60 .. 79
[12:25:46.261] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:25:46.261] <TB3> INFO: run 1 of 2
[12:26:01.346] <TB3> INFO: Test took 15085ms.
[12:26:01.375] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:01.375] <TB3> INFO: run 2 of 2
[12:26:16.526] <TB3> INFO: Test took 15151ms.
[12:26:16.554] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:16.555] <TB3> INFO: dacScan step from 80 .. 99
[12:26:16.555] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:26:16.555] <TB3> INFO: run 1 of 2
[12:26:27.798] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (68) != TBM ID (69)
[12:26:27.798] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (68) != TBM ID (69)
[12:26:27.798] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:26:27.798] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:26:28.507] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:26:28.507] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 1 readouts!
[12:26:28.508] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[12:26:28.508] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:26:28.508] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:26:32.678] <TB3> INFO: Test took 16123ms.
[12:26:32.746] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:32.753] <TB3> INFO: run 2 of 2
[12:26:48.833] <TB3> INFO: Test took 16075ms.
[12:26:48.912] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:48.921] <TB3> INFO: dacScan step from 100 .. 119
[12:26:48.921] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:26:48.921] <TB3> INFO: run 1 of 2
[12:27:07.822] <TB3> INFO: Test took 18901ms.
[12:27:07.965] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:07.990] <TB3> INFO: run 2 of 2
[12:27:26.957] <TB3> INFO: Test took 18967ms.
[12:27:27.126] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:27.155] <TB3> INFO: dacScan step from 120 .. 139
[12:27:27.155] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:27:27.155] <TB3> INFO: run 1 of 2
[12:27:47.344] <TB3> INFO: Test took 20189ms.
[12:27:47.509] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:47.538] <TB3> INFO: run 2 of 2
[12:28:06.430] <TB3> INFO: Test took 18892ms.
[12:28:06.588] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:06.618] <TB3> INFO: dacScan step from 140 .. 159
[12:28:06.618] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:28:06.618] <TB3> INFO: run 1 of 2
[12:28:26.150] <TB3> INFO: Test took 19532ms.
[12:28:26.321] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:26.357] <TB3> INFO: run 2 of 2
[12:28:39.436] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:28:39.436] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:28:39.436] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:28:39.436] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:28:46.539] <TB3> INFO: Test took 20182ms.
[12:28:46.712] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:46.743] <TB3> INFO: dacScan step from 160 .. 168
[12:28:46.743] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:28:46.743] <TB3> INFO: run 1 of 2
[12:28:53.479] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:28:57.481] <TB3> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[12:29:08.185] <TB3> INFO: Test took 10685ms.
[12:29:08.261] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:08.277] <TB3> INFO: run 2 of 2
[12:29:19.031] <TB3> INFO: Test took 10754ms.
[12:29:19.108] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:42.044] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 153 (20/5) hits flags = 16 (plus default)
[12:29:42.052] <TB3> INFO: dacScan step from 0 .. 19
[12:29:42.052] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:29:42.052] <TB3> INFO: run 1 of 2
[12:29:57.066] <TB3> INFO: Test took 15014ms.
[12:29:57.091] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:57.091] <TB3> INFO: run 2 of 2
[12:30:12.163] <TB3> INFO: Test took 15072ms.
[12:30:12.189] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:12.189] <TB3> INFO: dacScan step from 20 .. 39
[12:30:12.189] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:30:12.189] <TB3> INFO: run 1 of 2
[12:30:26.781] <TB3> INFO: Test took 14591ms.
[12:30:26.806] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:26.807] <TB3> INFO: run 2 of 2
[12:30:41.209] <TB3> INFO: Test took 14402ms.
[12:30:41.230] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:41.230] <TB3> INFO: dacScan step from 40 .. 59
[12:30:41.230] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:30:41.230] <TB3> INFO: run 1 of 2
[12:30:55.574] <TB3> INFO: Test took 14344ms.
[12:30:55.594] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:55.594] <TB3> INFO: run 2 of 2
[12:31:09.942] <TB3> INFO: Test took 14348ms.
[12:31:09.963] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:09.963] <TB3> INFO: dacScan step from 60 .. 79
[12:31:09.963] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:31:09.963] <TB3> INFO: run 1 of 2
[12:31:24.292] <TB3> INFO: Test took 14329ms.
[12:31:24.314] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:24.315] <TB3> INFO: run 2 of 2
[12:31:34.512] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (1) != Token Chain Length (4)
[12:31:34.512] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (0) != Token Chain Length (4)
[12:31:34.512] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:31:34.512] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:31:34.512] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:31:34.512] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:31:34.512] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:31:39.385] <TB3> INFO: Test took 15070ms.
[12:31:39.413] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:39.413] <TB3> INFO: dacScan step from 80 .. 99
[12:31:39.413] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:31:39.413] <TB3> INFO: run 1 of 2
[12:31:53.337] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (120) != TBM ID (121)
[12:31:53.337] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (120) != TBM ID (121)
[12:31:53.337] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:31:53.337] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:31:55.591] <TB3> INFO: Test took 16178ms.
[12:31:55.666] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:55.675] <TB3> INFO: run 2 of 2
[12:32:10.953] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:32:10.953] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 8 readouts!
[12:32:10.953] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:32:10.953] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:32:10.954] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:32:10.954] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:32:11.843] <TB3> INFO: Test took 16168ms.
[12:32:11.903] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:11.911] <TB3> INFO: dacScan step from 100 .. 119
[12:32:11.911] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:32:11.911] <TB3> INFO: run 1 of 2
[12:32:30.933] <TB3> INFO: Test took 19022ms.
[12:32:31.105] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:31.136] <TB3> INFO: run 2 of 2
[12:32:42.848] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:32:42.848] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:32:42.848] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:32:42.848] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:32:46.617] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:32:46.617] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:32:46.618] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:32:46.618] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:32:49.002] <TB3> INFO: Test took 17866ms.
[12:32:49.152] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:49.178] <TB3> INFO: dacScan step from 120 .. 139
[12:32:49.178] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:32:49.178] <TB3> INFO: run 1 of 2
[12:33:04.684] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:33:04.684] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[12:33:09.355] <TB3> INFO: Test took 20177ms.
[12:33:09.520] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:09.549] <TB3> INFO: run 2 of 2
[12:33:20.719] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:33:20.719] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:33:20.719] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:33:29.834] <TB3> INFO: Test took 20285ms.
[12:33:29.996] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:30.025] <TB3> INFO: dacScan step from 140 .. 153
[12:33:30.025] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:33:30.025] <TB3> INFO: run 1 of 2
[12:33:45.066] <TB3> INFO: Test took 15041ms.
[12:33:45.189] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:45.211] <TB3> INFO: run 2 of 2
[12:34:00.091] <TB3> INFO: Test took 14880ms.
[12:34:00.200] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:20.876] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 153 (20/5) hits flags = 16 (plus default)
[12:34:20.884] <TB3> INFO: dacScan step from 0 .. 19
[12:34:20.884] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:34:20.884] <TB3> INFO: run 1 of 2
[12:34:35.845] <TB3> INFO: Test took 14961ms.
[12:34:35.871] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:35.871] <TB3> INFO: run 2 of 2
[12:34:50.896] <TB3> INFO: Test took 15025ms.
[12:34:50.921] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:50.921] <TB3> INFO: dacScan step from 20 .. 39
[12:34:50.921] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:34:50.921] <TB3> INFO: run 1 of 2
[12:35:05.984] <TB3> INFO: Test took 15063ms.
[12:35:06.011] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:06.011] <TB3> INFO: run 2 of 2
[12:35:21.071] <TB3> INFO: Test took 15060ms.
[12:35:21.095] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:21.095] <TB3> INFO: dacScan step from 40 .. 59
[12:35:21.095] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:35:21.095] <TB3> INFO: run 1 of 2
[12:35:35.357] <TB3> INFO: Test took 14262ms.
[12:35:35.378] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:35.378] <TB3> INFO: run 2 of 2
[12:35:49.769] <TB3> INFO: Test took 14391ms.
[12:35:49.789] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:49.789] <TB3> INFO: dacScan step from 60 .. 79
[12:35:49.789] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:35:49.789] <TB3> INFO: run 1 of 2
[12:36:04.228] <TB3> INFO: Test took 14439ms.
[12:36:04.249] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:04.250] <TB3> INFO: run 2 of 2
[12:36:15.154] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (197) != TBM ID (198)
[12:36:15.154] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (197) != TBM ID (198)
[12:36:15.154] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:36:15.154] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:36:15.154] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:36:15.155] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:36:15.155] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:36:15.155] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:36:15.155] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:36:15.155] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:36:19.410] <TB3> INFO: Test took 15160ms.
[12:36:19.436] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:19.436] <TB3> INFO: dacScan step from 80 .. 99
[12:36:19.436] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:36:19.437] <TB3> INFO: run 1 of 2
[12:36:29.637] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:36:29.637] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:36:29.637] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:36:30.555] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:36:30.555] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:36:30.555] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:36:35.409] <TB3> INFO: Test took 15972ms.
[12:36:35.473] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:35.479] <TB3> INFO: run 2 of 2
[12:36:51.720] <TB3> INFO: Test took 16241ms.
[12:36:51.786] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:51.793] <TB3> INFO: dacScan step from 100 .. 119
[12:36:51.793] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:36:51.793] <TB3> INFO: run 1 of 2
[12:37:08.201] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:37:08.201] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (102) != TBM ID (112)
[12:37:08.201] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:37:08.201] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (102) != TBM ID (103)
[12:37:08.201] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (113) != TBM ID (103)
[12:37:08.201] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:37:08.201] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:37:08.201] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:37:08.201] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:37:10.820] <TB3> INFO: Test took 19027ms.
[12:37:10.977] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:11.004] <TB3> INFO: run 2 of 2
[12:37:28.070] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (203) != TBM ID (204)
[12:37:28.070] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (203) != TBM ID (204)
[12:37:28.070] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:37:28.070] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:37:28.784] <TB3> INFO: Test took 17780ms.
[12:37:28.933] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:28.960] <TB3> INFO: dacScan step from 120 .. 139
[12:37:28.960] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:37:28.960] <TB3> INFO: run 1 of 2
[12:37:42.688] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (134) != TBM ID (135)
[12:37:42.688] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (134) != TBM ID (135)
[12:37:42.688] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:37:42.688] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:37:43.986] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:37:43.986] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:37:43.991] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:37:43.991] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:37:47.631] <TB3> INFO: Test took 18671ms.
[12:37:47.792] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:47.822] <TB3> INFO: run 2 of 2
[12:38:07.310] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:38:07.310] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:38:07.310] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:38:07.310] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:38:08.118] <TB3> INFO: Test took 20296ms.
[12:38:08.286] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:08.315] <TB3> INFO: dacScan step from 140 .. 153
[12:38:08.315] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:38:08.315] <TB3> INFO: run 1 of 2
[12:38:23.295] <TB3> INFO: Test took 14980ms.
[12:38:23.419] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:23.441] <TB3> INFO: run 2 of 2
[12:38:38.403] <TB3> INFO: Test took 14961ms.
[12:38:38.524] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:01.724] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 153 (20/5) hits flags = 16 (plus default)
[12:39:01.732] <TB3> INFO: dacScan step from 0 .. 19
[12:39:01.732] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:39:01.732] <TB3> INFO: run 1 of 2
[12:39:16.861] <TB3> INFO: Test took 15129ms.
[12:39:16.883] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:16.883] <TB3> INFO: run 2 of 2
[12:39:32.046] <TB3> INFO: Test took 15163ms.
[12:39:32.071] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:32.071] <TB3> INFO: dacScan step from 20 .. 39
[12:39:32.071] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:39:32.071] <TB3> INFO: run 1 of 2
[12:39:47.176] <TB3> INFO: Test took 15105ms.
[12:39:47.201] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:47.201] <TB3> INFO: run 2 of 2
[12:40:02.182] <TB3> INFO: Test took 14981ms.
[12:40:02.206] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:02.206] <TB3> INFO: dacScan step from 40 .. 59
[12:40:02.206] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:40:02.206] <TB3> INFO: run 1 of 2
[12:40:17.286] <TB3> INFO: Test took 15080ms.
[12:40:17.311] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:17.311] <TB3> INFO: run 2 of 2
[12:40:32.362] <TB3> INFO: Test took 15051ms.
[12:40:32.384] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:32.384] <TB3> INFO: dacScan step from 60 .. 79
[12:40:32.384] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:40:32.384] <TB3> INFO: run 1 of 2
[12:40:45.013] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:40:45.013] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (177) != TBM ID (178)
[12:40:45.013] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (177) != TBM ID (178)
[12:40:45.013] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:40:45.013] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:40:45.013] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:40:45.013] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:40:45.013] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:40:45.013] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:40:45.013] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:40:46.793] <TB3> INFO: Test took 14409ms.
[12:40:46.815] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:46.815] <TB3> INFO: run 2 of 2
[12:41:01.120] <TB3> INFO: Test took 14305ms.
[12:41:01.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:01.144] <TB3> INFO: dacScan step from 80 .. 99
[12:41:01.144] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:41:01.144] <TB3> INFO: run 1 of 2
[12:41:11.812] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (3) != Token Chain Length (4)
[12:41:11.812] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (3) != Token Chain Length (4)
[12:41:12.106] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (169) != TBM ID (170)
[12:41:12.106] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (169) != TBM ID (170)
[12:41:12.106] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:41:12.107] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:41:14.724] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:41:14.724] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 5 readouts!
[12:41:14.724] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:41:14.724] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:41:14.724] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:41:14.724] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:41:16.375] <TB3> INFO: Test took 15231ms.
[12:41:16.438] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:16.446] <TB3> INFO: run 2 of 2
[12:41:32.658] <TB3> INFO: Test took 16212ms.
[12:41:32.729] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:32.737] <TB3> INFO: dacScan step from 100 .. 119
[12:41:32.737] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:41:32.737] <TB3> INFO: run 1 of 2
[12:41:47.970] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (5) != Token Chain Length (4)
[12:41:47.970] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 10 readouts!
[12:41:47.970] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 6 readouts!
[12:41:51.620] <TB3> INFO: Test took 18883ms.
[12:41:51.777] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:51.802] <TB3> INFO: run 2 of 2
[12:42:09.397] <TB3> INFO: Test took 17595ms.
[12:42:09.553] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:09.582] <TB3> INFO: dacScan step from 120 .. 139
[12:42:09.582] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:42:09.583] <TB3> INFO: run 1 of 2
[12:42:20.695] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (102) != TBM ID (103)
[12:42:20.695] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 1 Event ID mismatch: local ID (102) != TBM ID (103)
[12:42:20.695] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[12:42:20.695] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:42:29.701] <TB3> INFO: Test took 20118ms.
[12:42:29.882] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:29.914] <TB3> INFO: run 2 of 2
[12:42:50.223] <TB3> INFO: Test took 20309ms.
[12:42:50.381] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:50.409] <TB3> INFO: dacScan step from 140 .. 153
[12:42:50.409] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[12:42:50.409] <TB3> INFO: run 1 of 2
[12:43:05.245] <TB3> INFO: Test took 14836ms.
[12:43:05.357] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:05.378] <TB3> INFO: run 2 of 2
[12:43:20.394] <TB3> INFO: Test took 15016ms.
[12:43:20.505] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:43.324] <TB3> INFO: PixTestTrim::trimBitTest() done
[12:43:43.325] <TB3> INFO: PixTestTrim::doTest() done, duration: 2980 seconds
[12:43:44.044] <TB3> INFO: ######################################################################
[12:43:44.044] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:43:44.044] <TB3> INFO: ######################################################################
[12:43:47.455] <TB3> INFO: Test took 3410ms.
[12:43:47.482] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:51.178] <TB3> INFO: Test took 3497ms.
[12:43:51.243] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:54.722] <TB3> INFO: Test took 3467ms.
[12:43:54.794] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:54.801] <TB3> INFO: The DUT currently contains the following objects:
[12:43:54.801] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:43:54.801] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:43:54.801] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:43:54.801] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:43:54.801] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.801] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:54.802] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.911] <TB3> INFO: Test took 1109ms.
[12:43:55.912] <TB3> INFO: The DUT currently contains the following objects:
[12:43:55.912] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:43:55.912] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:43:55.912] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:43:55.913] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:43:55.913] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.913] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:55.915] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.021] <TB3> INFO: Test took 1106ms.
[12:43:57.022] <TB3> INFO: The DUT currently contains the following objects:
[12:43:57.022] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:43:57.022] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:43:57.022] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:43:57.023] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:43:57.023] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:57.023] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.130] <TB3> INFO: Test took 1106ms.
[12:43:58.133] <TB3> INFO: The DUT currently contains the following objects:
[12:43:58.133] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:43:58.133] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:43:58.133] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:43:58.133] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:43:58.133] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.133] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.134] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.134] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.134] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.134] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.134] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:58.134] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.239] <TB3> INFO: Test took 1105ms.
[12:43:59.240] <TB3> INFO: The DUT currently contains the following objects:
[12:43:59.240] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:43:59.240] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:43:59.240] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:43:59.240] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:43:59.240] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.240] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:43:59.241] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.347] <TB3> INFO: Test took 1106ms.
[12:44:00.348] <TB3> INFO: The DUT currently contains the following objects:
[12:44:00.358] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:00.358] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:00.358] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:00.359] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:00.359] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:00.359] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.455] <TB3> INFO: Test took 1096ms.
[12:44:01.457] <TB3> INFO: The DUT currently contains the following objects:
[12:44:01.457] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:01.457] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:01.457] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:01.457] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:01.457] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:01.457] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.566] <TB3> INFO: Test took 1109ms.
[12:44:02.567] <TB3> INFO: The DUT currently contains the following objects:
[12:44:02.567] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:02.567] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:02.567] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:02.567] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:02.567] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.567] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.567] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:02.568] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: Test took 1103ms.
[12:44:03.671] <TB3> INFO: The DUT currently contains the following objects:
[12:44:03.671] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:03.671] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:03.671] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:03.671] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:03.671] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:03.671] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.772] <TB3> INFO: Test took 1101ms.
[12:44:04.773] <TB3> INFO: The DUT currently contains the following objects:
[12:44:04.773] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:04.773] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:04.773] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:04.773] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:04.773] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:04.773] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: Test took 1101ms.
[12:44:05.874] <TB3> INFO: The DUT currently contains the following objects:
[12:44:05.874] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:05.874] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:05.874] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:05.874] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:05.874] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:05.874] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.975] <TB3> INFO: Test took 1101ms.
[12:44:06.975] <TB3> INFO: The DUT currently contains the following objects:
[12:44:06.975] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:06.975] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:06.975] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:06.975] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:06.975] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.975] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.975] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.975] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:06.976] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.076] <TB3> INFO: Test took 1100ms.
[12:44:08.077] <TB3> INFO: The DUT currently contains the following objects:
[12:44:08.077] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:08.077] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:08.077] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:08.077] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:08.077] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:08.077] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: Test took 1101ms.
[12:44:09.178] <TB3> INFO: The DUT currently contains the following objects:
[12:44:09.178] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:09.178] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:09.178] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:09.178] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:09.178] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:09.178] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.279] <TB3> INFO: Test took 1101ms.
[12:44:10.280] <TB3> INFO: The DUT currently contains the following objects:
[12:44:10.280] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:10.280] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:10.280] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:10.280] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:10.280] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:10.280] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: Test took 1101ms.
[12:44:11.381] <TB3> INFO: The DUT currently contains the following objects:
[12:44:11.381] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:44:11.381] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:44:11.381] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:44:11.381] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:44:11.381] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:11.381] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:44:12.482] <TB3> INFO: Test took 1101ms.
[12:44:12.485] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:44:19.815] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:44:25.835] <TB3> CRITICAL: <hal.cc/SingleRocOnePixelDacDacScan:L1547> Incomplete DAQ data readout! Missing -1 Events.
[12:44:25.873] <TB3> CRITICAL: <PixTestPhOptimization.cc/MaxPhVsDacDac:L868> pXar execption: Incomplete DAQ data readout in function SingleRocOnePixelDacDacScan
[12:44:25.873] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:48:07.001] <TB3> INFO: Test took 221128ms.
[12:48:08.534] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:48:44.106] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (2) != Token Chain Length (4)
[12:48:44.106] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:48:44.106] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:48:44.106] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:51:51.641] <TB3> INFO: Test took 223107ms.
[12:51:53.316] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.323] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.331] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.338] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.345] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:51:53.352] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.360] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.367] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:51:53.374] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:51:53.382] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:51:53.389] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.396] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.403] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.411] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:51:53.418] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:51:53.425] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:51:53.432] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:51:53.439] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[12:51:53.446] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.453] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.459] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.466] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.473] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.480] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.487] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:51:53.527] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:51:53.527] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:51:53.528] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:51:53.529] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:51:53.529] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:51:53.529] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:51:53.529] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:51:53.529] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:51:53.529] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:51:53.530] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:51:56.970] <TB3> INFO: Test took 3438ms.
[12:52:00.686] <TB3> INFO: Test took 3446ms.
[12:52:04.395] <TB3> INFO: Test took 3437ms.
[12:52:04.669] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:05.589] <TB3> INFO: Test took 920ms.
[12:52:05.593] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:06.701] <TB3> INFO: Test took 1108ms.
[12:52:06.705] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:07.813] <TB3> INFO: Test took 1108ms.
[12:52:07.816] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:08.925] <TB3> INFO: Test took 1109ms.
[12:52:08.928] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:10.036] <TB3> INFO: Test took 1108ms.
[12:52:10.040] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:11.147] <TB3> INFO: Test took 1107ms.
[12:52:11.150] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:12.257] <TB3> INFO: Test took 1107ms.
[12:52:12.261] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:13.369] <TB3> INFO: Test took 1108ms.
[12:52:13.373] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:14.481] <TB3> INFO: Test took 1108ms.
[12:52:14.484] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:15.594] <TB3> INFO: Test took 1110ms.
[12:52:15.598] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:16.707] <TB3> INFO: Test took 1109ms.
[12:52:16.710] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:17.818] <TB3> INFO: Test took 1108ms.
[12:52:17.821] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:18.931] <TB3> INFO: Test took 1110ms.
[12:52:18.934] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:20.044] <TB3> INFO: Test took 1110ms.
[12:52:20.047] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:21.155] <TB3> INFO: Test took 1108ms.
[12:52:21.159] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:22.267] <TB3> INFO: Test took 1108ms.
[12:52:22.270] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:23.379] <TB3> INFO: Test took 1109ms.
[12:52:23.383] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:24.493] <TB3> INFO: Test took 1110ms.
[12:52:24.496] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:25.619] <TB3> INFO: Test took 1123ms.
[12:52:25.622] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:26.728] <TB3> INFO: Test took 1106ms.
[12:52:26.731] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:27.841] <TB3> INFO: Test took 1110ms.
[12:52:27.844] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:28.952] <TB3> INFO: Test took 1108ms.
[12:52:28.956] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:30.064] <TB3> INFO: Test took 1109ms.
[12:52:30.067] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:31.177] <TB3> INFO: Test took 1110ms.
[12:52:31.181] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:32.290] <TB3> INFO: Test took 1109ms.
[12:52:32.293] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:33.403] <TB3> INFO: Test took 1110ms.
[12:52:33.406] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:34.514] <TB3> INFO: Test took 1108ms.
[12:52:34.518] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:35.627] <TB3> INFO: Test took 1109ms.
[12:52:35.631] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:36.733] <TB3> INFO: Test took 1102ms.
[12:52:36.735] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:37.845] <TB3> INFO: Test took 1110ms.
[12:52:37.849] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:38.957] <TB3> INFO: Test took 1108ms.
[12:52:38.961] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:52:40.069] <TB3> INFO: Test took 1108ms.
[12:52:40.605] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 536 seconds
[12:52:40.605] <TB3> INFO: PH scale (per ROC): 84 79 79 80 90 85 80 80 80 86 90 73 89 89 77 78
[12:52:40.605] <TB3> INFO: PH offset (per ROC): 148 176 145 141 164 176 150 176 176 155 135 189 154 162 173 161
[12:52:40.784] <TB3> INFO: ######################################################################
[12:52:40.784] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:52:40.784] <TB3> INFO: ######################################################################
[12:52:40.793] <TB3> INFO: scanning low vcal = 10
[12:52:44.638] <TB3> INFO: Test took 3845ms.
[12:52:44.642] <TB3> INFO: scanning low vcal = 20
[12:52:48.493] <TB3> INFO: Test took 3851ms.
[12:52:48.498] <TB3> INFO: scanning low vcal = 30
[12:52:52.366] <TB3> INFO: Test took 3867ms.
[12:52:52.379] <TB3> INFO: scanning low vcal = 40
[12:52:56.733] <TB3> INFO: Test took 4354ms.
[12:52:56.806] <TB3> INFO: scanning low vcal = 50
[12:53:01.168] <TB3> INFO: Test took 4362ms.
[12:53:01.230] <TB3> INFO: scanning low vcal = 60
[12:53:05.574] <TB3> INFO: Test took 4344ms.
[12:53:05.633] <TB3> INFO: scanning low vcal = 70
[12:53:09.926] <TB3> INFO: Test took 4293ms.
[12:53:09.992] <TB3> INFO: scanning low vcal = 80
[12:53:14.318] <TB3> INFO: Test took 4327ms.
[12:53:14.388] <TB3> INFO: scanning low vcal = 90
[12:53:18.712] <TB3> INFO: Test took 4324ms.
[12:53:18.782] <TB3> INFO: scanning low vcal = 100
[12:53:23.137] <TB3> INFO: Test took 4355ms.
[12:53:23.228] <TB3> INFO: scanning low vcal = 110
[12:53:27.578] <TB3> INFO: Test took 4350ms.
[12:53:27.663] <TB3> INFO: scanning low vcal = 120
[12:53:31.997] <TB3> INFO: Test took 4334ms.
[12:53:32.058] <TB3> INFO: scanning low vcal = 130
[12:53:36.414] <TB3> INFO: Test took 4356ms.
[12:53:36.482] <TB3> INFO: scanning low vcal = 140
[12:53:40.822] <TB3> INFO: Test took 4340ms.
[12:53:40.893] <TB3> INFO: scanning low vcal = 150
[12:53:45.259] <TB3> INFO: Test took 4366ms.
[12:53:45.328] <TB3> INFO: scanning low vcal = 160
[12:53:49.559] <TB3> INFO: Test took 4231ms.
[12:53:49.617] <TB3> INFO: scanning low vcal = 170
[12:53:53.880] <TB3> INFO: Test took 4262ms.
[12:53:53.978] <TB3> INFO: scanning low vcal = 180
[12:53:58.269] <TB3> INFO: Test took 4291ms.
[12:53:58.324] <TB3> INFO: scanning low vcal = 190
[12:54:02.623] <TB3> INFO: Test took 4299ms.
[12:54:02.678] <TB3> INFO: scanning low vcal = 200
[12:54:06.921] <TB3> INFO: Test took 4243ms.
[12:54:07.018] <TB3> INFO: scanning low vcal = 210
[12:54:11.310] <TB3> INFO: Test took 4292ms.
[12:54:11.369] <TB3> INFO: scanning low vcal = 220
[12:54:15.607] <TB3> INFO: Test took 4238ms.
[12:54:15.666] <TB3> INFO: scanning low vcal = 230
[12:54:19.868] <TB3> INFO: Test took 4202ms.
[12:54:19.935] <TB3> INFO: scanning low vcal = 240
[12:54:24.129] <TB3> INFO: Test took 4194ms.
[12:54:24.206] <TB3> INFO: scanning low vcal = 250
[12:54:28.452] <TB3> INFO: Test took 4246ms.
[12:54:28.514] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[12:54:32.711] <TB3> INFO: Test took 4197ms.
[12:54:32.770] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[12:54:36.981] <TB3> INFO: Test took 4211ms.
[12:54:37.042] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[12:54:41.264] <TB3> INFO: Test took 4222ms.
[12:54:41.322] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[12:54:45.560] <TB3> INFO: Test took 4238ms.
[12:54:45.624] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:54:49.858] <TB3> INFO: Test took 4234ms.
[12:54:50.373] <TB3> INFO: PixTestGainPedestal::measure() done
[12:55:23.923] <TB3> INFO: PixTestGainPedestal::fit() done
[12:55:23.923] <TB3> INFO: non-linearity mean: 0.949 0.949 0.957 0.953 0.953 0.961 0.954 0.957 0.958 0.966 0.957 0.950 0.953 0.952 0.958 0.954
[12:55:23.923] <TB3> INFO: non-linearity RMS: 0.006 0.006 0.005 0.005 0.006 0.005 0.006 0.006 0.005 0.006 0.005 0.011 0.007 0.006 0.006 0.006
[12:55:23.923] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[12:55:23.946] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[12:55:23.968] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[12:55:23.990] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[12:55:24.012] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[12:55:24.034] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[12:55:24.054] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[12:55:24.076] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[12:55:24.097] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[12:55:24.117] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[12:55:24.136] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[12:55:24.154] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[12:55:24.176] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[12:55:24.203] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[12:55:24.231] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[12:55:24.259] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[12:55:24.282] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 163 seconds
[12:55:24.288] <TB3> INFO: readReadbackCal: /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C0.dat .. /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C15.dat
[12:55:24.289] <TB3> INFO: PixTestReadback::doTest() start.
[12:55:24.290] <TB3> INFO: PixTestReadback::RES sent once
[12:55:40.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C0.dat
[12:55:40.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C1.dat
[12:55:40.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C2.dat
[12:55:40.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C3.dat
[12:55:40.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C4.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C5.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C6.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C7.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C8.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C9.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C10.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C11.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C12.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C13.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C14.dat
[12:55:40.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C15.dat
[12:55:40.806] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:55:40.806] <TB3> INFO: PixTestReadback::RES sent once
[12:55:57.257] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C0.dat
[12:55:57.262] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C1.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C2.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C3.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C4.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C5.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C6.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C7.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C8.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C9.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C10.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C11.dat
[12:55:57.263] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C12.dat
[12:55:57.264] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C13.dat
[12:55:57.264] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C14.dat
[12:55:57.264] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C15.dat
[12:55:57.302] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:55:57.302] <TB3> INFO: PixTestReadback::RES sent once
[12:56:10.033] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:56:10.033] <TB3> INFO: Vbg will be calibrated using Vd calibration
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 159.3calibrated Vbg = 1.20777 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156.3calibrated Vbg = 1.21104 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 146calibrated Vbg = 1.20658 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 141.9calibrated Vbg = 1.21435 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 154.8calibrated Vbg = 1.21264 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 155.9calibrated Vbg = 1.21541 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 159calibrated Vbg = 1.21944 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 149.8calibrated Vbg = 1.21406 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 154.3calibrated Vbg = 1.22085 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 159calibrated Vbg = 1.21401 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 148calibrated Vbg = 1.21329 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151.5calibrated Vbg = 1.21574 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 149.1calibrated Vbg = 1.20667 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 157calibrated Vbg = 1.1991 :::*/*/*/*/
[12:56:10.033] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 161.9calibrated Vbg = 1.20382 :::*/*/*/*/
[12:56:10.034] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 150.8calibrated Vbg = 1.19702 :::*/*/*/*/
[12:56:10.037] <TB3> INFO: PixTestReadback::RES sent once
[13:00:04.769] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C0.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C1.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C2.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C3.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C4.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C5.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C6.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C7.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C8.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C9.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C10.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C11.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C12.dat
[13:00:04.770] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C13.dat
[13:00:04.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C14.dat
[13:00:04.771] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2087_FullQualification_2015-08-25_10h29m_1440491371//002_FulltestPxar_m20//readbackCal_C15.dat
[13:00:04.792] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[13:00:04.792] <TB3> INFO: PixTestReadback::doTest() done
[13:00:04.806] <TB3> INFO: enter test to run
[13:00:04.806] <TB3> INFO: test: exit no parameter change
[13:00:05.387] <TB3> QUIET: Connection to board 170 closed.
[13:00:05.467] <TB3> INFO: pXar: this is the end, my friend