[14:42:24.726] <TB1> INFO: *** Welcome to pxar ***
[14:42:24.726] <TB1> INFO: *** Today: 2016/08/08
[14:42:24.824] <TB1> INFO: *** Version: 9751-dirty
[14:42:24.825] <TB1> INFO: readRocDacs: /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C0.dat .. /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C15.dat
[14:42:24.842] <TB1> INFO: readTbmDacs: /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//tbmParameters_C0b.dat
[14:42:24.845] <TB1> INFO: readMaskFile: /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//defaultMaskFile.dat
[14:42:24.846] <TB1> INFO: readTrimFile: /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters_C0.dat .. /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters_C15.dat
[14:42:24.953] <TB1> INFO: clk: 4
[14:42:24.953] <TB1> INFO: ctr: 4
[14:42:24.953] <TB1> INFO: sda: 19
[14:42:24.953] <TB1> INFO: tin: 9
[14:42:24.953] <TB1> INFO: level: 15
[14:42:24.953] <TB1> INFO: triggerdelay: 0
[14:42:24.954] <TB1> QUIET: Instanciating API for pxar v2.7.5+16~g4df2ad8
[14:42:24.954] <TB1> INFO: Log level: INFO
[14:42:24.961] <TB1> INFO: Found DTB DTB_WXC03A
[14:42:24.968] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[14:42:24.970] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 154
HW version: DTB1.2
FW version: 4.4
SW version: 4.6
Options:
USB id: DTB_WXC03A
MAC address: 40D85511809A
Hostname: pixelDTB154
Comment:
------------------------------------------------------
[14:42:24.973] <TB1> INFO: RPC call hashes of host and DTB match: 484264910
[14:42:26.510] <TB1> INFO: DUT info:
[14:42:26.510] <TB1> INFO: The DUT currently contains the following objects:
[14:42:26.510] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:42:26.510] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:42:26.510] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:42:26.510] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:42:26.510] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.510] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:26.912] <TB1> INFO: enter 'restricted' command line mode
[14:42:26.912] <TB1> INFO: enter test to run
[14:42:26.912] <TB1> INFO: test: pretest no parameter change
[14:42:26.912] <TB1> INFO: running: pretest
[14:42:26.919] <TB1> INFO: ----------------------------------------------------------------------
[14:42:26.919] <TB1> INFO: PixTestPretest::programROC()
[14:42:26.919] <TB1> INFO: ----------------------------------------------------------------------
[14:42:44.933] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:42:44.933] <TB1> INFO: IA differences per ROC: 18.5 16.9 20.1 18.5 16.9 19.3 16.9 19.3 20.1 20.1 20.1 18.5 18.5 17.7 18.5 18.5
[14:42:45.025] <TB1> INFO: enter test to run
[14:42:45.025] <TB1> INFO: test: pretest no parameter change
[14:42:45.025] <TB1> INFO: running: pretest
[14:42:45.027] <TB1> INFO: ----------------------------------------------------------------------
[14:42:45.027] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:42:45.027] <TB1> INFO: ----------------------------------------------------------------------
[14:42:51.214] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[14:42:51.214] <TB1> INFO: i(loss) [mA/ROC]: 19.3 20.1 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 20.1 18.5 18.5 20.1 18.5
[14:42:51.242] <TB1> INFO: enter test to run
[14:42:51.242] <TB1> INFO: test: pretest no parameter change
[14:42:51.242] <TB1> INFO: running: pretest
[14:42:51.242] <TB1> INFO: ----------------------------------------------------------------------
[14:42:51.242] <TB1> INFO: PixTestPretest::findTiming()
[14:42:51.242] <TB1> INFO: ----------------------------------------------------------------------
[14:42:51.242] <TB1> INFO: PixTestCmd::init()

[14:44:19.684] <TB1> INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):4, header/trailer: 1, token: 1
[14:44:19.685] <TB1> INFO: (success/tries = 100/100), width = 3
[14:44:19.685] <TB1> INFO: enter test to run
[14:44:19.685] <TB1> INFO: test: pretest no parameter change
[14:44:19.685] <TB1> INFO: running: pretest
[14:44:19.686] <TB1> INFO: ----------------------------------------------------------------------
[14:44:19.686] <TB1> INFO: PixTestPretest::findWorkingPixel()
[14:44:19.686] <TB1> INFO: ----------------------------------------------------------------------
[14:44:19.777] <TB1> INFO: Expecting 231680 events.


[14:44:29.917] <TB1> INFO: 231680 events read in total (9583ms).
[14:44:29.921] <TB1> INFO: Test took 10231ms.
[14:44:30.151] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:44:30.218] <TB1> INFO: enter test to run
[14:44:30.218] <TB1> INFO: test: pretest no parameter change
[14:44:30.218] <TB1> INFO: running: pretest
[14:44:30.219] <TB1> INFO: ----------------------------------------------------------------------
[14:44:30.219] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[14:44:30.219] <TB1> INFO: ----------------------------------------------------------------------
[14:44:30.311] <TB1> INFO: Expecting 231680 events.
[14:44:40.479] <TB1> INFO: 231680 events read in total (9612ms).
[14:44:40.483] <TB1> INFO: Test took 10260ms.
[14:44:40.729] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[14:44:40.729] <TB1> INFO: CalDel: 146 138 128 127 141 138 137 127 147 123 140 130 130 143 119 126
[14:44:40.729] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[14:44:40.765] <TB1> INFO: enter test to run
[14:44:40.765] <TB1> INFO: test: pretest no parameter change
[14:44:40.765] <TB1> INFO: running: pretest
[14:44:40.778] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C0.dat
[14:44:40.783] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C1.dat
[14:44:40.788] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C2.dat
[14:44:40.794] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C3.dat
[14:44:40.799] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C4.dat
[14:44:40.804] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C5.dat
[14:44:40.809] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C6.dat
[14:44:40.815] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C7.dat
[14:44:40.820] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C8.dat
[14:44:40.825] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C9.dat
[14:44:40.830] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C10.dat
[14:44:40.835] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C11.dat
[14:44:40.840] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C12.dat
[14:44:40.845] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C13.dat
[14:44:40.851] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C14.dat
[14:44:40.856] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters_C15.dat
[14:44:40.859] <TB1> INFO: enter test to run
[14:44:40.859] <TB1> INFO: test: fulltest no parameter change
[14:44:40.859] <TB1> INFO: running: fulltest
[14:44:40.859] <TB1> INFO: ######################################################################
[14:44:40.859] <TB1> INFO: PixTestFullTest::doTest()
[14:44:40.859] <TB1> INFO: ######################################################################
[14:44:40.860] <TB1> INFO: ######################################################################
[14:44:40.860] <TB1> INFO: PixTestAlive::doTest()
[14:44:40.860] <TB1> INFO: ######################################################################
[14:44:40.861] <TB1> INFO: ----------------------------------------------------------------------
[14:44:40.861] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:44:40.861] <TB1> INFO: ----------------------------------------------------------------------
[14:44:41.132] <TB1> INFO: Expecting 41600 events.
[14:44:44.926] <TB1> INFO: 41600 events read in total (3237ms).
[14:44:44.926] <TB1> INFO: Test took 4064ms.
[14:44:45.149] <TB1> INFO: PixTestAlive::aliveTest() done
[14:44:45.149] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[14:44:45.150] <TB1> INFO: ----------------------------------------------------------------------
[14:44:45.150] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:44:45.150] <TB1> INFO: ----------------------------------------------------------------------
[14:44:45.420] <TB1> INFO: Expecting 41600 events.
[14:44:48.366] <TB1> INFO: 41600 events read in total (2390ms).
[14:44:48.367] <TB1> INFO: Test took 3215ms.
[14:44:48.367] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:44:48.613] <TB1> INFO: PixTestAlive::maskTest() done
[14:44:48.613] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:44:48.614] <TB1> INFO: ----------------------------------------------------------------------
[14:44:48.614] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:44:48.614] <TB1> INFO: ----------------------------------------------------------------------
[14:44:48.944] <TB1> INFO: Expecting 41600 events.
[14:44:52.733] <TB1> INFO: 41600 events read in total (3233ms).
[14:44:52.734] <TB1> INFO: Test took 4119ms.
[14:44:52.958] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[14:44:52.958] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:44:52.958] <TB1> INFO: PixTestAlive::doTest() done, duration: 12 seconds
[14:44:52.958] <TB1> INFO: Decoding statistics:
[14:44:52.958] <TB1> INFO: General information:
[14:44:52.958] <TB1> INFO: 16bit words read: 0
[14:44:52.958] <TB1> INFO: valid events total: 0
[14:44:52.958] <TB1> INFO: empty events: 0
[14:44:52.958] <TB1> INFO: valid events with pixels: 0
[14:44:52.958] <TB1> INFO: valid pixel hits: 0
[14:44:52.958] <TB1> INFO: Event errors: 0
[14:44:52.958] <TB1> INFO: start marker: 0
[14:44:52.958] <TB1> INFO: stop marker: 0
[14:44:52.958] <TB1> INFO: overflow: 0
[14:44:52.958] <TB1> INFO: invalid 5bit words: 0
[14:44:52.958] <TB1> INFO: invalid XOR eye diagram: 0
[14:44:52.958] <TB1> INFO: frame (failed synchr.): 0
[14:44:52.958] <TB1> INFO: idle data (no TBM trl): 0
[14:44:52.958] <TB1> INFO: no data (only TBM hdr): 0
[14:44:52.958] <TB1> INFO: TBM errors: 0
[14:44:52.958] <TB1> INFO: flawed TBM headers: 0
[14:44:52.958] <TB1> INFO: flawed TBM trailers: 0
[14:44:52.958] <TB1> INFO: event ID mismatches: 0
[14:44:52.958] <TB1> INFO: ROC errors: 0
[14:44:52.958] <TB1> INFO: missing ROC header(s): 0
[14:44:52.958] <TB1> INFO: misplaced readback start: 0
[14:44:52.958] <TB1> INFO: Pixel decoding errors: 0
[14:44:52.958] <TB1> INFO: pixel data incomplete: 0
[14:44:52.958] <TB1> INFO: pixel address: 0
[14:44:52.958] <TB1> INFO: pulse height fill bit: 0
[14:44:52.958] <TB1> INFO: buffer corruption: 0
[14:44:52.965] <TB1> INFO: ######################################################################
[14:44:52.965] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:44:52.965] <TB1> INFO: ######################################################################
[14:44:52.967] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[14:44:52.979] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:44:52.979] <TB1> INFO: run 1 of 1
[14:44:53.256] <TB1> INFO: Expecting 3120000 events.
[14:45:34.423] <TB1> INFO: 860350 events read in total (40610ms).
[14:46:15.035] <TB1> INFO: 1712215 events read in total (81223ms).
[14:46:55.741] <TB1> INFO: 2574700 events read in total (121929ms).
[14:47:21.374] <TB1> INFO: 3120000 events read in total (147561ms).
[14:47:21.431] <TB1> INFO: Test took 148451ms.
[14:47:46.077] <TB1> INFO: PixTestBBMap::doTest() done, duration: 173 seconds
[14:47:46.077] <TB1> INFO: number of dead bumps (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:47:46.077] <TB1> INFO: separation cut (per ROC): 71 88 87 91 87 91 92 104 94 89 89 89 91 80 93 89
[14:47:46.077] <TB1> INFO: Decoding statistics:
[14:47:46.077] <TB1> INFO: General information:
[14:47:46.077] <TB1> INFO: 16bit words read: 0
[14:47:46.077] <TB1> INFO: valid events total: 0
[14:47:46.077] <TB1> INFO: empty events: 0
[14:47:46.077] <TB1> INFO: valid events with pixels: 0
[14:47:46.077] <TB1> INFO: valid pixel hits: 0
[14:47:46.077] <TB1> INFO: Event errors: 0
[14:47:46.077] <TB1> INFO: start marker: 0
[14:47:46.077] <TB1> INFO: stop marker: 0
[14:47:46.077] <TB1> INFO: overflow: 0
[14:47:46.077] <TB1> INFO: invalid 5bit words: 0
[14:47:46.077] <TB1> INFO: invalid XOR eye diagram: 0
[14:47:46.077] <TB1> INFO: frame (failed synchr.): 0
[14:47:46.077] <TB1> INFO: idle data (no TBM trl): 0
[14:47:46.077] <TB1> INFO: no data (only TBM hdr): 0
[14:47:46.077] <TB1> INFO: TBM errors: 0
[14:47:46.077] <TB1> INFO: flawed TBM headers: 0
[14:47:46.077] <TB1> INFO: flawed TBM trailers: 0
[14:47:46.077] <TB1> INFO: event ID mismatches: 0
[14:47:46.077] <TB1> INFO: ROC errors: 0
[14:47:46.077] <TB1> INFO: missing ROC header(s): 0
[14:47:46.077] <TB1> INFO: misplaced readback start: 0
[14:47:46.077] <TB1> INFO: Pixel decoding errors: 0
[14:47:46.077] <TB1> INFO: pixel data incomplete: 0
[14:47:46.077] <TB1> INFO: pixel address: 0
[14:47:46.077] <TB1> INFO: pulse height fill bit: 0
[14:47:46.077] <TB1> INFO: buffer corruption: 0
[14:47:46.149] <TB1> INFO: ######################################################################
[14:47:46.149] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:47:46.149] <TB1> INFO: ######################################################################
[14:47:46.149] <TB1> INFO: ----------------------------------------------------------------------
[14:47:46.149] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:47:46.149] <TB1> INFO: ----------------------------------------------------------------------
[14:47:46.149] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 150 (-1/-1) hits flags = 528 (plus default)
[14:47:46.157] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[14:47:46.157] <TB1> INFO: run 1 of 1
[14:47:46.458] <TB1> INFO: Expecting 26208000 events.
[14:48:20.723] <TB1> INFO: 934450 events read in total (33709ms).
[14:48:53.496] <TB1> INFO: 1851300 events read in total (66482ms).
[14:49:26.353] <TB1> INFO: 2769750 events read in total (99339ms).
[14:49:59.491] <TB1> INFO: 3688800 events read in total (132477ms).
[14:50:32.799] <TB1> INFO: 4605800 events read in total (165785ms).
[14:51:05.672] <TB1> INFO: 5520650 events read in total (198658ms).
[14:51:38.612] <TB1> INFO: 6433750 events read in total (231598ms).
[14:52:11.714] <TB1> INFO: 7345400 events read in total (264700ms).
[14:52:44.616] <TB1> INFO: 8258500 events read in total (297602ms).
[14:53:17.897] <TB1> INFO: 9171800 events read in total (330883ms).
[14:53:50.949] <TB1> INFO: 10081350 events read in total (363935ms).
[14:54:23.753] <TB1> INFO: 10989100 events read in total (396739ms).
[14:54:56.947] <TB1> INFO: 11897050 events read in total (429933ms).
[14:55:30.188] <TB1> INFO: 12804350 events read in total (463174ms).
[14:56:04.557] <TB1> INFO: 13703100 events read in total (497543ms).
[14:56:38.638] <TB1> INFO: 14599850 events read in total (531624ms).
[14:57:12.951] <TB1> INFO: 15495950 events read in total (565937ms).
[14:57:45.826] <TB1> INFO: 16388350 events read in total (598813ms).
[14:58:18.708] <TB1> INFO: 17280400 events read in total (631694ms).
[14:58:51.798] <TB1> INFO: 18172900 events read in total (664784ms).
[14:59:24.749] <TB1> INFO: 19063750 events read in total (697735ms).
[14:59:57.650] <TB1> INFO: 19955200 events read in total (730636ms).
[15:00:30.592] <TB1> INFO: 20846200 events read in total (763578ms).
[15:01:03.673] <TB1> INFO: 21738650 events read in total (796659ms).
[15:01:36.487] <TB1> INFO: 22626500 events read in total (829473ms).
[15:02:09.509] <TB1> INFO: 23516600 events read in total (862495ms).
[15:02:42.322] <TB1> INFO: 24408650 events read in total (895308ms).
[15:03:15.451] <TB1> INFO: 25302350 events read in total (928437ms).
[15:03:48.565] <TB1> INFO: 26208000 events read in total (961551ms).
[15:03:48.596] <TB1> INFO: Test took 962438ms.
[15:03:48.831] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:50.354] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:51.879] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:53.327] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:54.756] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:56.221] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:57.643] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:59.100] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:00.646] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:02.106] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:03.815] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:05.301] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:06.836] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:08.304] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:09.838] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:11.532] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:04:13.350] <TB1> INFO: PixTestScurves::scurves() done
[15:04:13.350] <TB1> INFO: Vcal mean: 82.07 95.47 87.36 98.82 95.04 100.03 105.62 106.72 104.99 102.50 98.64 93.03 101.38 85.90 99.44 91.46
[15:04:13.350] <TB1> INFO: Vcal RMS: 4.66 4.74 4.97 5.05 5.34 5.58 5.62 5.39 5.08 4.81 5.27 5.13 5.24 5.12 5.49 4.76
[15:04:13.350] <TB1> INFO: PixTestScurves::fullTest() done, duration: 987 seconds
[15:04:13.350] <TB1> INFO: Decoding statistics:
[15:04:13.350] <TB1> INFO: General information:
[15:04:13.350] <TB1> INFO: 16bit words read: 0
[15:04:13.350] <TB1> INFO: valid events total: 0
[15:04:13.350] <TB1> INFO: empty events: 0
[15:04:13.350] <TB1> INFO: valid events with pixels: 0
[15:04:13.350] <TB1> INFO: valid pixel hits: 0
[15:04:13.350] <TB1> INFO: Event errors: 0
[15:04:13.350] <TB1> INFO: start marker: 0
[15:04:13.350] <TB1> INFO: stop marker: 0
[15:04:13.350] <TB1> INFO: overflow: 0
[15:04:13.350] <TB1> INFO: invalid 5bit words: 0
[15:04:13.350] <TB1> INFO: invalid XOR eye diagram: 0
[15:04:13.350] <TB1> INFO: frame (failed synchr.): 0
[15:04:13.350] <TB1> INFO: idle data (no TBM trl): 0
[15:04:13.350] <TB1> INFO: no data (only TBM hdr): 0
[15:04:13.350] <TB1> INFO: TBM errors: 0
[15:04:13.350] <TB1> INFO: flawed TBM headers: 0
[15:04:13.350] <TB1> INFO: flawed TBM trailers: 0
[15:04:13.350] <TB1> INFO: event ID mismatches: 0
[15:04:13.350] <TB1> INFO: ROC errors: 0
[15:04:13.350] <TB1> INFO: missing ROC header(s): 0
[15:04:13.350] <TB1> INFO: misplaced readback start: 0
[15:04:13.350] <TB1> INFO: Pixel decoding errors: 0
[15:04:13.350] <TB1> INFO: pixel data incomplete: 0
[15:04:13.350] <TB1> INFO: pixel address: 0
[15:04:13.350] <TB1> INFO: pulse height fill bit: 0
[15:04:13.350] <TB1> INFO: buffer corruption: 0
[15:04:13.448] <TB1> INFO: ######################################################################
[15:04:13.448] <TB1> INFO: PixTestTrim::doTest()
[15:04:13.448] <TB1> INFO: ######################################################################
[15:04:13.449] <TB1> INFO: ----------------------------------------------------------------------
[15:04:13.449] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[15:04:13.449] <TB1> INFO: ----------------------------------------------------------------------
[15:04:13.551] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:04:13.551] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 10 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:04:13.560] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:04:13.561] <TB1> INFO: run 1 of 1
[15:04:13.847] <TB1> INFO: Expecting 6281600 events.
[15:04:53.751] <TB1> INFO: 1068660 events read in total (39346ms).
[15:05:32.620] <TB1> INFO: 2131800 events read in total (78215ms).
[15:06:11.346] <TB1> INFO: 3191940 events read in total (116941ms).
[15:06:50.268] <TB1> INFO: 4259600 events read in total (155863ms).
[15:07:29.384] <TB1> INFO: 5334180 events read in total (194979ms).
[15:08:03.720] <TB1> INFO: 6281600 events read in total (229315ms).
[15:08:03.753] <TB1> INFO: Test took 230192ms.
[15:08:24.516] <TB1> INFO: ROC 0 VthrComp = 84
[15:08:24.516] <TB1> INFO: ROC 1 VthrComp = 98
[15:08:24.516] <TB1> INFO: ROC 2 VthrComp = 92
[15:08:24.516] <TB1> INFO: ROC 3 VthrComp = 100
[15:08:24.516] <TB1> INFO: ROC 4 VthrComp = 91
[15:08:24.517] <TB1> INFO: ROC 5 VthrComp = 99
[15:08:24.517] <TB1> INFO: ROC 6 VthrComp = 104
[15:08:24.517] <TB1> INFO: ROC 7 VthrComp = 108
[15:08:24.517] <TB1> INFO: ROC 8 VthrComp = 101
[15:08:24.517] <TB1> INFO: ROC 9 VthrComp = 106
[15:08:24.517] <TB1> INFO: ROC 10 VthrComp = 100
[15:08:24.517] <TB1> INFO: ROC 11 VthrComp = 93
[15:08:24.517] <TB1> INFO: ROC 12 VthrComp = 103
[15:08:24.517] <TB1> INFO: ROC 13 VthrComp = 91
[15:08:24.517] <TB1> INFO: ROC 14 VthrComp = 101
[15:08:24.518] <TB1> INFO: ROC 15 VthrComp = 94
[15:08:24.518] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:08:24.518] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 10 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:08:24.528] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:08:24.528] <TB1> INFO: run 1 of 1
[15:08:24.815] <TB1> INFO: Expecting 6281600 events.
[15:09:00.410] <TB1> INFO: 755910 events read in total (35038ms).
[15:09:35.931] <TB1> INFO: 1509850 events read in total (70559ms).
[15:10:10.908] <TB1> INFO: 2264610 events read in total (105536ms).
[15:10:45.847] <TB1> INFO: 3019410 events read in total (140475ms).
[15:11:20.596] <TB1> INFO: 3768670 events read in total (175224ms).
[15:11:55.380] <TB1> INFO: 4513930 events read in total (210008ms).
[15:12:30.409] <TB1> INFO: 5257010 events read in total (245037ms).
[15:13:05.332] <TB1> INFO: 5999970 events read in total (279960ms).
[15:13:18.803] <TB1> INFO: 6281600 events read in total (293431ms).
[15:13:18.848] <TB1> INFO: Test took 294321ms.
[15:13:47.476] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 57.1088 for pixel 23/15 mean/min/max = 44.8438/32.4067/57.2809
[15:13:47.476] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 57.0734 for pixel 0/51 mean/min/max = 44.6977/32.3021/57.0933
[15:13:47.477] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 56.8193 for pixel 9/71 mean/min/max = 44.8138/32.7222/56.9053
[15:13:47.477] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 56.7021 for pixel 29/6 mean/min/max = 44.4647/31.9585/56.9708
[15:13:47.477] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 61.6835 for pixel 0/62 mean/min/max = 47.4931/33.2516/61.7345
[15:13:47.477] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 58.9088 for pixel 6/1 mean/min/max = 45.1739/31.319/59.0288
[15:13:47.478] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 62.5896 for pixel 11/79 mean/min/max = 48.117/33.5132/62.7208
[15:13:47.478] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 61.8561 for pixel 6/4 mean/min/max = 48.5202/35.0382/62.0022
[15:13:47.478] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 58.23 for pixel 51/8 mean/min/max = 45.4369/32.5758/58.2979
[15:13:47.478] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 57.4826 for pixel 13/73 mean/min/max = 46.4108/35.2895/57.5322
[15:13:47.479] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 59.0938 for pixel 0/10 mean/min/max = 45.7844/32.4457/59.1231
[15:13:47.479] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 58.1043 for pixel 9/4 mean/min/max = 45.5374/32.9449/58.1298
[15:13:47.479] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 57.3015 for pixel 24/73 mean/min/max = 44.6555/31.9797/57.3314
[15:13:47.480] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 57.6151 for pixel 20/45 mean/min/max = 45.211/32.4743/57.9478
[15:13:47.480] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 56.4574 for pixel 22/79 mean/min/max = 44.0514/31.4762/56.6266
[15:13:47.480] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 55.9047 for pixel 51/79 mean/min/max = 44.6655/33.0674/56.2636
[15:13:47.481] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:13:47.571] <TB1> INFO: Expecting 514560 events.
[15:14:00.633] <TB1> INFO: 514560 events read in total (12505ms).
[15:14:00.638] <TB1> INFO: Expecting 514560 events.
[15:14:13.428] <TB1> INFO: 514560 events read in total (12369ms).
[15:14:13.435] <TB1> INFO: Expecting 514560 events.
[15:14:26.257] <TB1> INFO: 514560 events read in total (12406ms).
[15:14:26.267] <TB1> INFO: Expecting 514560 events.
[15:14:39.102] <TB1> INFO: 514560 events read in total (12420ms).
[15:14:39.113] <TB1> INFO: Expecting 514560 events.
[15:14:51.870] <TB1> INFO: 514560 events read in total (12347ms).
[15:14:51.883] <TB1> INFO: Expecting 514560 events.
[15:15:04.521] <TB1> INFO: 514560 events read in total (12223ms).
[15:15:04.536] <TB1> INFO: Expecting 514560 events.
[15:15:17.278] <TB1> INFO: 514560 events read in total (12334ms).
[15:15:17.295] <TB1> INFO: Expecting 514560 events.
[15:15:30.185] <TB1> INFO: 514560 events read in total (12485ms).
[15:15:30.204] <TB1> INFO: Expecting 514560 events.
[15:15:42.849] <TB1> INFO: 514560 events read in total (12243ms).
[15:15:42.870] <TB1> INFO: Expecting 514560 events.
[15:15:55.685] <TB1> INFO: 514560 events read in total (12405ms).
[15:15:55.710] <TB1> INFO: Expecting 514560 events.
[15:16:08.434] <TB1> INFO: 514560 events read in total (12323ms).
[15:16:08.460] <TB1> INFO: Expecting 514560 events.
[15:16:21.206] <TB1> INFO: 514560 events read in total (12344ms).
[15:16:21.234] <TB1> INFO: Expecting 514560 events.
[15:16:33.989] <TB1> INFO: 514560 events read in total (12353ms).
[15:16:34.018] <TB1> INFO: Expecting 514560 events.
[15:16:46.876] <TB1> INFO: 514560 events read in total (12457ms).
[15:16:46.908] <TB1> INFO: Expecting 514560 events.
[15:16:59.617] <TB1> INFO: 514560 events read in total (12307ms).
[15:16:59.652] <TB1> INFO: Expecting 514560 events.
[15:17:12.275] <TB1> INFO: 514560 events read in total (12221ms).
[15:17:12.313] <TB1> INFO: Test took 204832ms.
[15:17:13.333] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[15:17:13.341] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:17:13.341] <TB1> INFO: run 1 of 1
[15:17:13.612] <TB1> INFO: Expecting 6281600 events.
[15:17:48.526] <TB1> INFO: 744160 events read in total (34358ms).
[15:18:22.977] <TB1> INFO: 1487090 events read in total (68809ms).
[15:18:57.473] <TB1> INFO: 2230650 events read in total (103305ms).
[15:19:31.814] <TB1> INFO: 2974190 events read in total (137646ms).
[15:20:06.319] <TB1> INFO: 3711890 events read in total (172151ms).
[15:20:40.884] <TB1> INFO: 4444510 events read in total (206716ms).
[15:21:15.857] <TB1> INFO: 5174360 events read in total (241690ms).
[15:21:50.188] <TB1> INFO: 5902830 events read in total (276020ms).
[15:22:08.097] <TB1> INFO: 6281600 events read in total (293929ms).
[15:22:08.141] <TB1> INFO: Test took 294800ms.
[15:22:33.654] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.084160 .. 255.000000
[15:22:33.736] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 10 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[15:22:33.744] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:22:33.744] <TB1> INFO: run 1 of 1
[15:22:34.088] <TB1> INFO: Expecting 10649600 events.
[15:23:08.865] <TB1> INFO: 712330 events read in total (34220ms).
[15:23:43.574] <TB1> INFO: 1424870 events read in total (68929ms).
[15:24:17.792] <TB1> INFO: 2137600 events read in total (103147ms).
[15:24:52.154] <TB1> INFO: 2850770 events read in total (137509ms).
[15:25:27.610] <TB1> INFO: 3563380 events read in total (172965ms).
[15:26:02.988] <TB1> INFO: 4276360 events read in total (208343ms).
[15:26:38.292] <TB1> INFO: 4989200 events read in total (243647ms).
[15:27:13.017] <TB1> INFO: 5702200 events read in total (278372ms).
[15:27:47.228] <TB1> INFO: 6415030 events read in total (312583ms).
[15:28:21.596] <TB1> INFO: 7126820 events read in total (346951ms).
[15:28:56.156] <TB1> INFO: 7838580 events read in total (381511ms).
[15:29:30.335] <TB1> INFO: 8549660 events read in total (415690ms).
[15:30:04.542] <TB1> INFO: 9260540 events read in total (449897ms).
[15:30:38.571] <TB1> INFO: 9971000 events read in total (483926ms).
[15:31:11.085] <TB1> INFO: 10649600 events read in total (516440ms).
[15:31:11.182] <TB1> INFO: Test took 517437ms.
[15:31:42.199] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 13.447774 .. 45.678802
[15:31:42.278] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 10 dacrange: 3 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:31:42.286] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:31:42.286] <TB1> INFO: run 1 of 1
[15:31:42.557] <TB1> INFO: Expecting 2204800 events.
[15:32:21.369] <TB1> INFO: 948800 events read in total (38256ms).
[15:32:59.845] <TB1> INFO: 1895860 events read in total (76732ms).
[15:33:12.380] <TB1> INFO: 2204800 events read in total (89267ms).
[15:33:12.391] <TB1> INFO: Test took 90105ms.
[15:33:26.378] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 2.860129 .. 42.495045
[15:33:26.456] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 10 dacrange: 2 .. 52 (-1/-1) hits flags = 528 (plus default)
[15:33:26.464] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:33:26.464] <TB1> INFO: run 1 of 1
[15:33:26.727] <TB1> INFO: Expecting 2121600 events.
[15:34:05.603] <TB1> INFO: 981470 events read in total (38320ms).
[15:34:43.646] <TB1> INFO: 1961350 events read in total (76363ms).
[15:34:50.231] <TB1> INFO: 2121600 events read in total (82948ms).
[15:34:50.245] <TB1> INFO: Test took 83781ms.
[15:35:04.213] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 2.860129 .. 42.080215
[15:35:04.319] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 10 dacrange: 2 .. 52 (-1/-1) hits flags = 528 (plus default)
[15:35:04.328] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:35:04.328] <TB1> INFO: run 1 of 1
[15:35:04.616] <TB1> INFO: Expecting 2121600 events.
[15:35:43.950] <TB1> INFO: 982110 events read in total (38778ms).
[15:36:22.336] <TB1> INFO: 1963390 events read in total (77165ms).
[15:36:28.821] <TB1> INFO: 2121600 events read in total (83649ms).
[15:36:28.835] <TB1> INFO: Test took 84507ms.
[15:36:42.290] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:36:42.290] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:36:42.298] <TB1> INFO: dacScan split into 1 runs with ntrig = 10
[15:36:42.298] <TB1> INFO: run 1 of 1
[15:36:42.566] <TB1> INFO: Expecting 1705600 events.
[15:37:20.221] <TB1> INFO: 878230 events read in total (37099ms).
[15:37:55.000] <TB1> INFO: 1705600 events read in total (71878ms).
[15:37:55.011] <TB1> INFO: Test took 72712ms.
[15:38:08.665] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C0.dat
[15:38:08.669] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C1.dat
[15:38:08.673] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C2.dat
[15:38:08.677] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C3.dat
[15:38:08.680] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C4.dat
[15:38:08.684] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C5.dat
[15:38:08.688] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C6.dat
[15:38:08.692] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C7.dat
[15:38:08.698] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C8.dat
[15:38:08.702] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C9.dat
[15:38:08.706] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C10.dat
[15:38:08.709] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C11.dat
[15:38:08.713] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C12.dat
[15:38:08.718] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C13.dat
[15:38:08.723] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C14.dat
[15:38:08.727] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C15.dat
[15:38:08.730] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C0.dat
[15:38:08.742] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C1.dat
[15:38:08.753] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C2.dat
[15:38:08.764] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C3.dat
[15:38:08.777] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C4.dat
[15:38:08.788] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C5.dat
[15:38:08.800] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C6.dat
[15:38:08.811] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C7.dat
[15:38:08.822] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C8.dat
[15:38:08.833] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C9.dat
[15:38:08.844] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C10.dat
[15:38:08.855] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C11.dat
[15:38:08.867] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C12.dat
[15:38:08.878] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C13.dat
[15:38:08.889] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C14.dat
[15:38:08.900] <TB1> INFO: write trim parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//trimParameters35_C15.dat
[15:38:08.912] <TB1> INFO: PixTestTrim::trimTest() done
[15:38:08.912] <TB1> INFO: vtrim: 95 94 101 104 107 106 120 140 91 111 103 103 103 111 92 87
[15:38:08.912] <TB1> INFO: vthrcomp: 84 98 92 100 91 99 104 108 101 106 100 93 103 91 101 94
[15:38:08.912] <TB1> INFO: vcal mean: 34.93 34.93 34.98 34.96 34.95 34.90 34.99 35.02 34.99 34.99 35.00 34.99 34.99 34.97 34.94 35.00
[15:38:08.912] <TB1> INFO: vcal RMS: 0.84 0.79 0.81 0.87 1.01 1.04 1.05 0.86 0.87 0.83 0.86 0.81 0.95 0.98 0.86 0.78
[15:38:08.913] <TB1> INFO: bits mean: 9.82 9.41 9.05 9.79 8.67 10.01 8.92 8.49 9.39 8.94 9.17 9.35 9.67 9.48 9.94 8.95
[15:38:08.913] <TB1> INFO: bits RMS: 2.57 2.75 2.86 2.63 2.89 2.60 2.53 2.49 2.73 2.41 2.78 2.62 2.68 2.63 2.75 2.82
[15:38:08.919] <TB1> INFO: ----------------------------------------------------------------------
[15:38:08.919] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[15:38:08.919] <TB1> INFO: ----------------------------------------------------------------------
[15:38:08.921] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[15:38:08.929] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:38:08.929] <TB1> INFO: run 1 of 1
[15:38:09.195] <TB1> INFO: Expecting 4160000 events.
[15:38:53.117] <TB1> INFO: 957055 events read in total (43366ms).
[15:39:35.204] <TB1> INFO: 1905280 events read in total (85454ms).
[15:40:16.681] <TB1> INFO: 2842965 events read in total (126930ms).
[15:40:58.146] <TB1> INFO: 3777395 events read in total (168395ms).
[15:41:15.152] <TB1> INFO: 4160000 events read in total (185401ms).
[15:41:15.187] <TB1> INFO: Test took 186258ms.
[15:41:46.024] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 173 (-1/-1) hits flags = 528 (plus default)
[15:41:46.033] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:41:46.033] <TB1> INFO: run 1 of 1
[15:41:46.298] <TB1> INFO: Expecting 3619200 events.
[15:42:30.028] <TB1> INFO: 980980 events read in total (43174ms).
[15:43:12.378] <TB1> INFO: 1950475 events read in total (85524ms).
[15:43:54.591] <TB1> INFO: 2908335 events read in total (127737ms).
[15:44:25.826] <TB1> INFO: 3619200 events read in total (158972ms).
[15:44:25.872] <TB1> INFO: Test took 159839ms.
[15:44:53.687] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 159 (-1/-1) hits flags = 528 (plus default)
[15:44:53.695] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:44:53.695] <TB1> INFO: run 1 of 1
[15:44:53.962] <TB1> INFO: Expecting 3328000 events.
[15:45:38.040] <TB1> INFO: 1022985 events read in total (43522ms).
[15:46:21.424] <TB1> INFO: 2029600 events read in total (86906ms).
[15:47:04.324] <TB1> INFO: 3025140 events read in total (129806ms).
[15:47:17.360] <TB1> INFO: 3328000 events read in total (142842ms).
[15:47:17.390] <TB1> INFO: Test took 143694ms.
[15:47:42.119] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 159 (-1/-1) hits flags = 528 (plus default)
[15:47:42.128] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:47:42.128] <TB1> INFO: run 1 of 1
[15:47:42.394] <TB1> INFO: Expecting 3328000 events.
[15:48:25.946] <TB1> INFO: 1022715 events read in total (42996ms).
[15:49:08.699] <TB1> INFO: 2028790 events read in total (85749ms).
[15:49:51.342] <TB1> INFO: 3023755 events read in total (128392ms).
[15:50:04.708] <TB1> INFO: 3328000 events read in total (141758ms).
[15:50:04.744] <TB1> INFO: Test took 142616ms.
[15:50:29.515] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 159 (-1/-1) hits flags = 528 (plus default)
[15:50:29.530] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:50:29.530] <TB1> INFO: run 1 of 1
[15:50:29.794] <TB1> INFO: Expecting 3328000 events.
[15:51:13.313] <TB1> INFO: 1021485 events read in total (42963ms).
[15:51:56.047] <TB1> INFO: 2027100 events read in total (85697ms).
[15:52:38.629] <TB1> INFO: 3021375 events read in total (128279ms).
[15:52:52.021] <TB1> INFO: 3328000 events read in total (141671ms).
[15:52:52.051] <TB1> INFO: Test took 142521ms.
[15:53:16.130] <TB1> INFO: PixTestTrim::trimBitTest() done
[15:53:16.131] <TB1> INFO: PixTestTrim::doTest() done, duration: 2942 seconds
[15:53:16.131] <TB1> INFO: Decoding statistics:
[15:53:16.131] <TB1> INFO: General information:
[15:53:16.131] <TB1> INFO: 16bit words read: 0
[15:53:16.131] <TB1> INFO: valid events total: 0
[15:53:16.131] <TB1> INFO: empty events: 0
[15:53:16.131] <TB1> INFO: valid events with pixels: 0
[15:53:16.131] <TB1> INFO: valid pixel hits: 0
[15:53:16.131] <TB1> INFO: Event errors: 0
[15:53:16.131] <TB1> INFO: start marker: 0
[15:53:16.131] <TB1> INFO: stop marker: 0
[15:53:16.131] <TB1> INFO: overflow: 0
[15:53:16.131] <TB1> INFO: invalid 5bit words: 0
[15:53:16.131] <TB1> INFO: invalid XOR eye diagram: 0
[15:53:16.131] <TB1> INFO: frame (failed synchr.): 0
[15:53:16.131] <TB1> INFO: idle data (no TBM trl): 0
[15:53:16.131] <TB1> INFO: no data (only TBM hdr): 0
[15:53:16.131] <TB1> INFO: TBM errors: 0
[15:53:16.131] <TB1> INFO: flawed TBM headers: 0
[15:53:16.131] <TB1> INFO: flawed TBM trailers: 0
[15:53:16.131] <TB1> INFO: event ID mismatches: 0
[15:53:16.131] <TB1> INFO: ROC errors: 0
[15:53:16.131] <TB1> INFO: missing ROC header(s): 0
[15:53:16.131] <TB1> INFO: misplaced readback start: 0
[15:53:16.131] <TB1> INFO: Pixel decoding errors: 0
[15:53:16.131] <TB1> INFO: pixel data incomplete: 0
[15:53:16.131] <TB1> INFO: pixel address: 0
[15:53:16.131] <TB1> INFO: pulse height fill bit: 0
[15:53:16.131] <TB1> INFO: buffer corruption: 0
[15:53:16.809] <TB1> INFO: ######################################################################
[15:53:16.809] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:53:16.809] <TB1> INFO: ######################################################################
[15:53:17.072] <TB1> INFO: Expecting 41600 events.
[15:53:20.807] <TB1> INFO: 41600 events read in total (3179ms).
[15:53:20.807] <TB1> INFO: Test took 3997ms.
[15:53:21.274] <TB1> INFO: Expecting 41600 events.
[15:53:25.074] <TB1> INFO: 41600 events read in total (3244ms).
[15:53:25.075] <TB1> INFO: Test took 4068ms.
[15:53:25.380] <TB1> INFO: Expecting 41600 events.
[15:53:29.185] <TB1> INFO: 41600 events read in total (3249ms).
[15:53:29.186] <TB1> INFO: Test took 4089ms.
[15:53:29.440] <TB1> INFO: Expecting 2560 events.
[15:53:30.294] <TB1> INFO: 2560 events read in total (298ms).
[15:53:30.294] <TB1> INFO: Test took 1096ms.
[15:53:30.600] <TB1> INFO: Expecting 2560 events.
[15:53:31.452] <TB1> INFO: 2560 events read in total (296ms).
[15:53:31.452] <TB1> INFO: Test took 1157ms.
[15:53:31.758] <TB1> INFO: Expecting 2560 events.
[15:53:32.610] <TB1> INFO: 2560 events read in total (296ms).
[15:53:32.611] <TB1> INFO: Test took 1158ms.
[15:53:32.916] <TB1> INFO: Expecting 2560 events.
[15:53:33.769] <TB1> INFO: 2560 events read in total (297ms).
[15:53:33.769] <TB1> INFO: Test took 1158ms.
[15:53:34.074] <TB1> INFO: Expecting 2560 events.
[15:53:34.927] <TB1> INFO: 2560 events read in total (296ms).
[15:53:34.927] <TB1> INFO: Test took 1157ms.
[15:53:35.235] <TB1> INFO: Expecting 2560 events.
[15:53:36.088] <TB1> INFO: 2560 events read in total (297ms).
[15:53:36.088] <TB1> INFO: Test took 1161ms.
[15:53:36.393] <TB1> INFO: Expecting 2560 events.
[15:53:37.245] <TB1> INFO: 2560 events read in total (296ms).
[15:53:37.245] <TB1> INFO: Test took 1157ms.
[15:53:37.550] <TB1> INFO: Expecting 2560 events.
[15:53:38.402] <TB1> INFO: 2560 events read in total (296ms).
[15:53:38.403] <TB1> INFO: Test took 1157ms.
[15:53:38.708] <TB1> INFO: Expecting 2560 events.
[15:53:39.560] <TB1> INFO: 2560 events read in total (296ms).
[15:53:39.561] <TB1> INFO: Test took 1158ms.
[15:53:39.868] <TB1> INFO: Expecting 2560 events.
[15:53:40.723] <TB1> INFO: 2560 events read in total (298ms).
[15:53:40.723] <TB1> INFO: Test took 1162ms.
[15:53:41.028] <TB1> INFO: Expecting 2560 events.
[15:53:41.880] <TB1> INFO: 2560 events read in total (296ms).
[15:53:41.880] <TB1> INFO: Test took 1157ms.
[15:53:42.185] <TB1> INFO: Expecting 2560 events.
[15:53:43.038] <TB1> INFO: 2560 events read in total (297ms).
[15:53:43.039] <TB1> INFO: Test took 1159ms.
[15:53:43.344] <TB1> INFO: Expecting 2560 events.
[15:53:44.198] <TB1> INFO: 2560 events read in total (298ms).
[15:53:44.198] <TB1> INFO: Test took 1159ms.
[15:53:44.503] <TB1> INFO: Expecting 2560 events.
[15:53:45.355] <TB1> INFO: 2560 events read in total (296ms).
[15:53:45.355] <TB1> INFO: Test took 1157ms.
[15:53:45.661] <TB1> INFO: Expecting 2560 events.
[15:53:46.514] <TB1> INFO: 2560 events read in total (297ms).
[15:53:46.514] <TB1> INFO: Test took 1158ms.
[15:53:46.819] <TB1> INFO: Expecting 2560 events.
[15:53:47.671] <TB1> INFO: 2560 events read in total (296ms).
[15:53:47.671] <TB1> INFO: Test took 1157ms.
[15:53:47.674] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:53:47.977] <TB1> INFO: Expecting 655360 events.
[15:54:04.617] <TB1> INFO: 655360 events read in total (16083ms).
[15:54:04.626] <TB1> INFO: Expecting 655360 events.
[15:54:21.291] <TB1> INFO: 655360 events read in total (16264ms).
[15:54:21.304] <TB1> INFO: Expecting 655360 events.
[15:54:38.006] <TB1> INFO: 655360 events read in total (16300ms).
[15:54:38.021] <TB1> INFO: Expecting 655360 events.
[15:54:54.710] <TB1> INFO: 655360 events read in total (16287ms).
[15:54:54.731] <TB1> INFO: Expecting 655360 events.
[15:55:11.314] <TB1> INFO: 655360 events read in total (16182ms).
[15:55:11.336] <TB1> INFO: Expecting 655360 events.
[15:55:28.065] <TB1> INFO: 655360 events read in total (16327ms).
[15:55:28.104] <TB1> INFO: Expecting 655360 events.
[15:55:44.759] <TB1> INFO: 655360 events read in total (16253ms).
[15:55:44.789] <TB1> INFO: Expecting 655360 events.
[15:56:01.313] <TB1> INFO: 655360 events read in total (16122ms).
[15:56:01.347] <TB1> INFO: Expecting 655360 events.
[15:56:18.004] <TB1> INFO: 655360 events read in total (16255ms).
[15:56:18.044] <TB1> INFO: Expecting 655360 events.
[15:56:34.653] <TB1> INFO: 655360 events read in total (16208ms).
[15:56:34.694] <TB1> INFO: Expecting 655360 events.
[15:56:51.390] <TB1> INFO: 655360 events read in total (16294ms).
[15:56:51.434] <TB1> INFO: Expecting 655360 events.
[15:57:08.034] <TB1> INFO: 655360 events read in total (16198ms).
[15:57:08.081] <TB1> INFO: Expecting 655360 events.
[15:57:24.653] <TB1> INFO: 655360 events read in total (16170ms).
[15:57:24.703] <TB1> INFO: Expecting 655360 events.
[15:57:41.308] <TB1> INFO: 655360 events read in total (16203ms).
[15:57:41.365] <TB1> INFO: Expecting 655360 events.
[15:57:57.908] <TB1> INFO: 655360 events read in total (16141ms).
[15:57:57.966] <TB1> INFO: Expecting 655360 events.
[15:58:14.560] <TB1> INFO: 655360 events read in total (16192ms).
[15:58:14.620] <TB1> INFO: Test took 266946ms.
[15:58:14.698] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:58:14.929] <TB1> INFO: Expecting 655360 events.
[15:58:31.504] <TB1> INFO: 655360 events read in total (16019ms).
[15:58:31.513] <TB1> INFO: Expecting 655360 events.
[15:58:47.985] <TB1> INFO: 655360 events read in total (16070ms).
[15:58:47.997] <TB1> INFO: Expecting 655360 events.
[15:59:04.479] <TB1> INFO: 655360 events read in total (16080ms).
[15:59:04.496] <TB1> INFO: Expecting 655360 events.
[15:59:21.039] <TB1> INFO: 655360 events read in total (16142ms).
[15:59:21.058] <TB1> INFO: Expecting 655360 events.
[15:59:37.721] <TB1> INFO: 655360 events read in total (16261ms).
[15:59:37.743] <TB1> INFO: Expecting 655360 events.
[15:59:54.112] <TB1> INFO: 655360 events read in total (15967ms).
[15:59:54.137] <TB1> INFO: Expecting 655360 events.
[16:00:10.602] <TB1> INFO: 655360 events read in total (16063ms).
[16:00:10.632] <TB1> INFO: Expecting 655360 events.
[16:00:27.146] <TB1> INFO: 655360 events read in total (16112ms).
[16:00:27.178] <TB1> INFO: Expecting 655360 events.
[16:00:43.634] <TB1> INFO: 655360 events read in total (16054ms).
[16:00:43.671] <TB1> INFO: Expecting 655360 events.
[16:01:00.146] <TB1> INFO: 655360 events read in total (16073ms).
[16:01:00.187] <TB1> INFO: Expecting 655360 events.
[16:01:16.642] <TB1> INFO: 655360 events read in total (16053ms).
[16:01:16.688] <TB1> INFO: Expecting 655360 events.
[16:01:33.260] <TB1> INFO: 655360 events read in total (16171ms).
[16:01:33.306] <TB1> INFO: Expecting 655360 events.
[16:01:49.865] <TB1> INFO: 655360 events read in total (16157ms).
[16:01:49.918] <TB1> INFO: Expecting 655360 events.
[16:02:06.491] <TB1> INFO: 655360 events read in total (16172ms).
[16:02:06.542] <TB1> INFO: Expecting 655360 events.
[16:02:23.129] <TB1> INFO: 655360 events read in total (16185ms).
[16:02:23.190] <TB1> INFO: Expecting 655360 events.
[16:02:39.892] <TB1> INFO: 655360 events read in total (16300ms).
[16:02:39.956] <TB1> INFO: Test took 265258ms.
[16:02:40.153] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.160] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:02:40.170] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[16:02:40.179] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[16:02:40.186] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[16:02:40.192] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.199] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:02:40.206] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[16:02:40.213] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[16:02:40.220] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.227] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.234] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.241] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.247] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.254] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.261] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.269] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.276] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.283] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.291] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.301] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.308] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.315] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:40.349] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C0.dat
[16:02:40.355] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C1.dat
[16:02:40.360] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C2.dat
[16:02:40.365] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C3.dat
[16:02:40.372] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C4.dat
[16:02:40.377] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C5.dat
[16:02:40.382] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C6.dat
[16:02:40.387] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C7.dat
[16:02:40.392] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C8.dat
[16:02:40.397] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C9.dat
[16:02:40.402] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C10.dat
[16:02:40.409] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C11.dat
[16:02:40.414] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C12.dat
[16:02:40.419] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C13.dat
[16:02:40.425] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C14.dat
[16:02:40.431] <TB1> INFO: write dac parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//dacParameters35_C15.dat
[16:02:40.718] <TB1> INFO: Expecting 41600 events.
[16:02:44.178] <TB1> INFO: 41600 events read in total (2904ms).
[16:02:44.179] <TB1> INFO: Test took 3742ms.
[16:02:44.621] <TB1> INFO: Expecting 41600 events.
[16:02:48.092] <TB1> INFO: 41600 events read in total (2914ms).
[16:02:48.093] <TB1> INFO: Test took 3737ms.
[16:02:48.536] <TB1> INFO: Expecting 41600 events.
[16:02:51.993] <TB1> INFO: 41600 events read in total (2901ms).
[16:02:51.994] <TB1> INFO: Test took 3723ms.
[16:02:52.174] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:52.262] <TB1> INFO: Expecting 2560 events.
[16:02:53.115] <TB1> INFO: 2560 events read in total (297ms).
[16:02:53.115] <TB1> INFO: Test took 941ms.
[16:02:53.117] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:53.421] <TB1> INFO: Expecting 2560 events.
[16:02:54.274] <TB1> INFO: 2560 events read in total (297ms).
[16:02:54.274] <TB1> INFO: Test took 1157ms.
[16:02:54.276] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:54.580] <TB1> INFO: Expecting 2560 events.
[16:02:55.436] <TB1> INFO: 2560 events read in total (300ms).
[16:02:55.437] <TB1> INFO: Test took 1161ms.
[16:02:55.438] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:55.742] <TB1> INFO: Expecting 2560 events.
[16:02:56.595] <TB1> INFO: 2560 events read in total (296ms).
[16:02:56.595] <TB1> INFO: Test took 1157ms.
[16:02:56.597] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:56.901] <TB1> INFO: Expecting 2560 events.
[16:02:57.754] <TB1> INFO: 2560 events read in total (297ms).
[16:02:57.755] <TB1> INFO: Test took 1158ms.
[16:02:57.757] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:58.060] <TB1> INFO: Expecting 2560 events.
[16:02:58.917] <TB1> INFO: 2560 events read in total (301ms).
[16:02:58.918] <TB1> INFO: Test took 1161ms.
[16:02:58.919] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:59.224] <TB1> INFO: Expecting 2560 events.
[16:03:00.077] <TB1> INFO: 2560 events read in total (297ms).
[16:03:00.077] <TB1> INFO: Test took 1158ms.
[16:03:00.078] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:00.384] <TB1> INFO: Expecting 2560 events.
[16:03:01.238] <TB1> INFO: 2560 events read in total (298ms).
[16:03:01.239] <TB1> INFO: Test took 1161ms.
[16:03:01.241] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:01.544] <TB1> INFO: Expecting 2560 events.
[16:03:02.397] <TB1> INFO: 2560 events read in total (297ms).
[16:03:02.397] <TB1> INFO: Test took 1156ms.
[16:03:02.400] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:02.703] <TB1> INFO: Expecting 2560 events.
[16:03:03.558] <TB1> INFO: 2560 events read in total (298ms).
[16:03:03.558] <TB1> INFO: Test took 1158ms.
[16:03:03.560] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:03.864] <TB1> INFO: Expecting 2560 events.
[16:03:04.716] <TB1> INFO: 2560 events read in total (296ms).
[16:03:04.717] <TB1> INFO: Test took 1157ms.
[16:03:04.719] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:05.024] <TB1> INFO: Expecting 2560 events.
[16:03:05.878] <TB1> INFO: 2560 events read in total (298ms).
[16:03:05.878] <TB1> INFO: Test took 1159ms.
[16:03:05.880] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:06.184] <TB1> INFO: Expecting 2560 events.
[16:03:07.042] <TB1> INFO: 2560 events read in total (302ms).
[16:03:07.042] <TB1> INFO: Test took 1162ms.
[16:03:07.044] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:07.348] <TB1> INFO: Expecting 2560 events.
[16:03:08.204] <TB1> INFO: 2560 events read in total (300ms).
[16:03:08.204] <TB1> INFO: Test took 1160ms.
[16:03:08.206] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:08.509] <TB1> INFO: Expecting 2560 events.
[16:03:09.362] <TB1> INFO: 2560 events read in total (296ms).
[16:03:09.362] <TB1> INFO: Test took 1156ms.
[16:03:09.364] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:09.669] <TB1> INFO: Expecting 2560 events.
[16:03:10.523] <TB1> INFO: 2560 events read in total (298ms).
[16:03:10.523] <TB1> INFO: Test took 1159ms.
[16:03:10.524] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:10.830] <TB1> INFO: Expecting 2560 events.
[16:03:11.683] <TB1> INFO: 2560 events read in total (297ms).
[16:03:11.683] <TB1> INFO: Test took 1159ms.
[16:03:11.685] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:11.989] <TB1> INFO: Expecting 2560 events.
[16:03:12.842] <TB1> INFO: 2560 events read in total (296ms).
[16:03:12.842] <TB1> INFO: Test took 1157ms.
[16:03:12.844] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:13.148] <TB1> INFO: Expecting 2560 events.
[16:03:14.000] <TB1> INFO: 2560 events read in total (296ms).
[16:03:14.000] <TB1> INFO: Test took 1156ms.
[16:03:14.002] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:14.306] <TB1> INFO: Expecting 2560 events.
[16:03:15.166] <TB1> INFO: 2560 events read in total (303ms).
[16:03:15.167] <TB1> INFO: Test took 1165ms.
[16:03:15.169] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:15.473] <TB1> INFO: Expecting 2560 events.
[16:03:16.331] <TB1> INFO: 2560 events read in total (302ms).
[16:03:16.331] <TB1> INFO: Test took 1162ms.
[16:03:16.334] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:16.637] <TB1> INFO: Expecting 2560 events.
[16:03:17.497] <TB1> INFO: 2560 events read in total (304ms).
[16:03:17.497] <TB1> INFO: Test took 1163ms.
[16:03:17.499] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:17.802] <TB1> INFO: Expecting 2560 events.
[16:03:18.655] <TB1> INFO: 2560 events read in total (297ms).
[16:03:18.656] <TB1> INFO: Test took 1157ms.
[16:03:18.658] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:18.961] <TB1> INFO: Expecting 2560 events.
[16:03:19.818] <TB1> INFO: 2560 events read in total (301ms).
[16:03:19.818] <TB1> INFO: Test took 1160ms.
[16:03:19.820] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:20.124] <TB1> INFO: Expecting 2560 events.
[16:03:20.979] <TB1> INFO: 2560 events read in total (299ms).
[16:03:20.979] <TB1> INFO: Test took 1159ms.
[16:03:20.982] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:21.284] <TB1> INFO: Expecting 2560 events.
[16:03:22.137] <TB1> INFO: 2560 events read in total (297ms).
[16:03:22.137] <TB1> INFO: Test took 1156ms.
[16:03:22.138] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:22.443] <TB1> INFO: Expecting 2560 events.
[16:03:23.298] <TB1> INFO: 2560 events read in total (299ms).
[16:03:23.298] <TB1> INFO: Test took 1160ms.
[16:03:23.300] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:23.604] <TB1> INFO: Expecting 2560 events.
[16:03:24.458] <TB1> INFO: 2560 events read in total (298ms).
[16:03:24.458] <TB1> INFO: Test took 1159ms.
[16:03:24.460] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:24.764] <TB1> INFO: Expecting 2560 events.
[16:03:25.618] <TB1> INFO: 2560 events read in total (297ms).
[16:03:25.618] <TB1> INFO: Test took 1159ms.
[16:03:25.620] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:25.924] <TB1> INFO: Expecting 2560 events.
[16:03:26.777] <TB1> INFO: 2560 events read in total (297ms).
[16:03:26.777] <TB1> INFO: Test took 1157ms.
[16:03:26.779] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:27.083] <TB1> INFO: Expecting 2560 events.
[16:03:27.936] <TB1> INFO: 2560 events read in total (297ms).
[16:03:27.936] <TB1> INFO: Test took 1157ms.
[16:03:27.939] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:28.242] <TB1> INFO: Expecting 2560 events.
[16:03:29.098] <TB1> INFO: 2560 events read in total (300ms).
[16:03:29.098] <TB1> INFO: Test took 1160ms.
[16:03:29.573] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 612 seconds
[16:03:29.573] <TB1> INFO: PH scale (per ROC): 73 75 80 76 69 70 66 74 75 75 73 80 74 83 83 76
[16:03:29.573] <TB1> INFO: PH offset (per ROC): 176 176 161 177 174 194 177 175 187 166 177 164 187 165 170 170
[16:03:29.577] <TB1> INFO: Decoding statistics:
[16:03:29.577] <TB1> INFO: General information:
[16:03:29.577] <TB1> INFO: 16bit words read: 91940
[16:03:29.577] <TB1> INFO: valid events total: 10240
[16:03:29.577] <TB1> INFO: empty events: 7735
[16:03:29.577] <TB1> INFO: valid events with pixels: 2505
[16:03:29.577] <TB1> INFO: valid pixel hits: 2505
[16:03:29.577] <TB1> INFO: Event errors: 0
[16:03:29.577] <TB1> INFO: start marker: 0
[16:03:29.577] <TB1> INFO: stop marker: 0
[16:03:29.577] <TB1> INFO: overflow: 0
[16:03:29.577] <TB1> INFO: invalid 5bit words: 0
[16:03:29.577] <TB1> INFO: invalid XOR eye diagram: 0
[16:03:29.577] <TB1> INFO: frame (failed synchr.): 0
[16:03:29.577] <TB1> INFO: idle data (no TBM trl): 0
[16:03:29.577] <TB1> INFO: no data (only TBM hdr): 0
[16:03:29.577] <TB1> INFO: TBM errors: 0
[16:03:29.577] <TB1> INFO: flawed TBM headers: 0
[16:03:29.577] <TB1> INFO: flawed TBM trailers: 0
[16:03:29.577] <TB1> INFO: event ID mismatches: 0
[16:03:29.577] <TB1> INFO: ROC errors: 0
[16:03:29.577] <TB1> INFO: missing ROC header(s): 0
[16:03:29.577] <TB1> INFO: misplaced readback start: 0
[16:03:29.577] <TB1> INFO: Pixel decoding errors: 0
[16:03:29.577] <TB1> INFO: pixel data incomplete: 0
[16:03:29.577] <TB1> INFO: pixel address: 0
[16:03:29.577] <TB1> INFO: pulse height fill bit: 0
[16:03:29.577] <TB1> INFO: buffer corruption: 0
[16:03:29.758] <TB1> INFO: ######################################################################
[16:03:29.758] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[16:03:29.758] <TB1> INFO: ######################################################################
[16:03:29.767] <TB1> INFO: scanning low vcal = 10
[16:03:30.039] <TB1> INFO: Expecting 41600 events.
[16:03:33.586] <TB1> INFO: 41600 events read in total (2991ms).
[16:03:33.586] <TB1> INFO: Test took 3819ms.
[16:03:33.587] <TB1> INFO: scanning low vcal = 20
[16:03:33.892] <TB1> INFO: Expecting 41600 events.
[16:03:37.439] <TB1> INFO: 41600 events read in total (2991ms).
[16:03:37.440] <TB1> INFO: Test took 3853ms.
[16:03:37.441] <TB1> INFO: scanning low vcal = 30
[16:03:37.746] <TB1> INFO: Expecting 41600 events.
[16:03:41.311] <TB1> INFO: 41600 events read in total (3009ms).
[16:03:41.311] <TB1> INFO: Test took 3870ms.
[16:03:41.313] <TB1> INFO: scanning low vcal = 40
[16:03:41.602] <TB1> INFO: Expecting 41600 events.
[16:03:45.740] <TB1> INFO: 41600 events read in total (3581ms).
[16:03:45.741] <TB1> INFO: Test took 4428ms.
[16:03:45.743] <TB1> INFO: scanning low vcal = 50
[16:03:46.004] <TB1> INFO: Expecting 41600 events.
[16:03:50.205] <TB1> INFO: 41600 events read in total (3645ms).
[16:03:50.205] <TB1> INFO: Test took 4462ms.
[16:03:50.208] <TB1> INFO: scanning low vcal = 60
[16:03:50.477] <TB1> INFO: Expecting 41600 events.
[16:03:54.658] <TB1> INFO: 41600 events read in total (3625ms).
[16:03:54.659] <TB1> INFO: Test took 4451ms.
[16:03:54.661] <TB1> INFO: scanning low vcal = 70
[16:03:54.955] <TB1> INFO: Expecting 41600 events.
[16:03:59.129] <TB1> INFO: 41600 events read in total (3617ms).
[16:03:59.129] <TB1> INFO: Test took 4468ms.
[16:03:59.132] <TB1> INFO: scanning low vcal = 80
[16:03:59.391] <TB1> INFO: Expecting 41600 events.
[16:04:03.590] <TB1> INFO: 41600 events read in total (3643ms).
[16:04:03.591] <TB1> INFO: Test took 4459ms.
[16:04:03.594] <TB1> INFO: scanning low vcal = 90
[16:04:03.856] <TB1> INFO: Expecting 41600 events.
[16:04:08.054] <TB1> INFO: 41600 events read in total (3642ms).
[16:04:08.055] <TB1> INFO: Test took 4461ms.
[16:04:08.058] <TB1> INFO: scanning low vcal = 100
[16:04:08.321] <TB1> INFO: Expecting 41600 events.
[16:04:12.544] <TB1> INFO: 41600 events read in total (3667ms).
[16:04:12.544] <TB1> INFO: Test took 4486ms.
[16:04:12.546] <TB1> INFO: scanning low vcal = 110
[16:04:12.809] <TB1> INFO: Expecting 41600 events.
[16:04:17.005] <TB1> INFO: 41600 events read in total (3640ms).
[16:04:17.006] <TB1> INFO: Test took 4459ms.
[16:04:17.009] <TB1> INFO: scanning low vcal = 120
[16:04:17.272] <TB1> INFO: Expecting 41600 events.
[16:04:21.469] <TB1> INFO: 41600 events read in total (3641ms).
[16:04:21.469] <TB1> INFO: Test took 4460ms.
[16:04:21.472] <TB1> INFO: scanning low vcal = 130
[16:04:21.734] <TB1> INFO: Expecting 41600 events.
[16:04:25.909] <TB1> INFO: 41600 events read in total (3619ms).
[16:04:25.909] <TB1> INFO: Test took 4437ms.
[16:04:25.912] <TB1> INFO: scanning low vcal = 140
[16:04:26.171] <TB1> INFO: Expecting 41600 events.
[16:04:30.346] <TB1> INFO: 41600 events read in total (3619ms).
[16:04:30.347] <TB1> INFO: Test took 4435ms.
[16:04:30.350] <TB1> INFO: scanning low vcal = 150
[16:04:30.612] <TB1> INFO: Expecting 41600 events.
[16:04:34.823] <TB1> INFO: 41600 events read in total (3655ms).
[16:04:34.823] <TB1> INFO: Test took 4473ms.
[16:04:34.826] <TB1> INFO: scanning low vcal = 160
[16:04:35.092] <TB1> INFO: Expecting 41600 events.
[16:04:39.259] <TB1> INFO: 41600 events read in total (3611ms).
[16:04:39.260] <TB1> INFO: Test took 4434ms.
[16:04:39.263] <TB1> INFO: scanning low vcal = 170
[16:04:39.526] <TB1> INFO: Expecting 41600 events.
[16:04:43.698] <TB1> INFO: 41600 events read in total (3616ms).
[16:04:43.698] <TB1> INFO: Test took 4435ms.
[16:04:43.702] <TB1> INFO: scanning low vcal = 180
[16:04:43.968] <TB1> INFO: Expecting 41600 events.
[16:04:48.149] <TB1> INFO: 41600 events read in total (3625ms).
[16:04:48.149] <TB1> INFO: Test took 4447ms.
[16:04:48.152] <TB1> INFO: scanning low vcal = 190
[16:04:48.411] <TB1> INFO: Expecting 41600 events.
[16:04:52.583] <TB1> INFO: 41600 events read in total (3616ms).
[16:04:52.584] <TB1> INFO: Test took 4432ms.
[16:04:52.587] <TB1> INFO: scanning low vcal = 200
[16:04:52.855] <TB1> INFO: Expecting 41600 events.
[16:04:57.032] <TB1> INFO: 41600 events read in total (3621ms).
[16:04:57.032] <TB1> INFO: Test took 4445ms.
[16:04:57.035] <TB1> INFO: scanning low vcal = 210
[16:04:57.303] <TB1> INFO: Expecting 41600 events.
[16:05:01.492] <TB1> INFO: 41600 events read in total (3632ms).
[16:05:01.493] <TB1> INFO: Test took 4458ms.
[16:05:01.495] <TB1> INFO: scanning low vcal = 220
[16:05:01.757] <TB1> INFO: Expecting 41600 events.
[16:05:05.935] <TB1> INFO: 41600 events read in total (3622ms).
[16:05:05.936] <TB1> INFO: Test took 4441ms.
[16:05:05.938] <TB1> INFO: scanning low vcal = 230
[16:05:06.196] <TB1> INFO: Expecting 41600 events.
[16:05:10.376] <TB1> INFO: 41600 events read in total (3624ms).
[16:05:10.377] <TB1> INFO: Test took 4439ms.
[16:05:10.379] <TB1> INFO: scanning low vcal = 240
[16:05:10.643] <TB1> INFO: Expecting 41600 events.
[16:05:14.813] <TB1> INFO: 41600 events read in total (3614ms).
[16:05:14.814] <TB1> INFO: Test took 4435ms.
[16:05:14.816] <TB1> INFO: scanning low vcal = 250
[16:05:15.079] <TB1> INFO: Expecting 41600 events.
[16:05:19.247] <TB1> INFO: 41600 events read in total (3611ms).
[16:05:19.247] <TB1> INFO: Test took 4431ms.
[16:05:19.251] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[16:05:19.513] <TB1> INFO: Expecting 41600 events.
[16:05:23.699] <TB1> INFO: 41600 events read in total (3630ms).
[16:05:23.700] <TB1> INFO: Test took 4449ms.
[16:05:23.702] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[16:05:23.963] <TB1> INFO: Expecting 41600 events.
[16:05:28.148] <TB1> INFO: 41600 events read in total (3629ms).
[16:05:28.149] <TB1> INFO: Test took 4447ms.
[16:05:28.151] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[16:05:28.412] <TB1> INFO: Expecting 41600 events.
[16:05:32.589] <TB1> INFO: 41600 events read in total (3621ms).
[16:05:32.590] <TB1> INFO: Test took 4439ms.
[16:05:32.592] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[16:05:32.851] <TB1> INFO: Expecting 41600 events.
[16:05:37.013] <TB1> INFO: 41600 events read in total (3605ms).
[16:05:37.014] <TB1> INFO: Test took 4422ms.
[16:05:37.016] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[16:05:37.281] <TB1> INFO: Expecting 41600 events.
[16:05:41.457] <TB1> INFO: 41600 events read in total (3620ms).
[16:05:41.458] <TB1> INFO: Test took 4442ms.
[16:05:42.496] <TB1> INFO: PixTestGainPedestal::measure() done
[16:06:15.800] <TB1> INFO: PixTestGainPedestal::fit() done
[16:06:15.800] <TB1> INFO: non-linearity mean: 0.959 0.954 0.955 0.953 0.952 0.956 0.956 0.949 0.947 0.956 0.957 0.945 0.960 0.952 0.960 0.956
[16:06:15.800] <TB1> INFO: non-linearity RMS: 0.006 0.006 0.006 0.007 0.008 0.007 0.007 0.007 0.009 0.006 0.007 0.007 0.008 0.007 0.007 0.007
[16:06:15.801] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[16:06:15.842] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[16:06:15.879] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[16:06:15.916] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[16:06:15.958] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[16:06:15.995] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[16:06:16.036] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[16:06:16.074] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[16:06:16.112] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[16:06:16.148] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[16:06:16.187] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[16:06:16.223] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[16:06:16.259] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[16:06:16.299] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[16:06:16.338] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[16:06:16.378] <TB1> INFO: write gain/ped parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[16:06:16.416] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 166 seconds
[16:06:16.416] <TB1> INFO: Decoding statistics:
[16:06:16.416] <TB1> INFO: General information:
[16:06:16.416] <TB1> INFO: 16bit words read: 2662400
[16:06:16.416] <TB1> INFO: valid events total: 166400
[16:06:16.416] <TB1> INFO: empty events: 0
[16:06:16.416] <TB1> INFO: valid events with pixels: 166400
[16:06:16.416] <TB1> INFO: valid pixel hits: 665549
[16:06:16.416] <TB1> INFO: Event errors: 0
[16:06:16.416] <TB1> INFO: start marker: 0
[16:06:16.416] <TB1> INFO: stop marker: 0
[16:06:16.417] <TB1> INFO: overflow: 0
[16:06:16.417] <TB1> INFO: invalid 5bit words: 0
[16:06:16.417] <TB1> INFO: invalid XOR eye diagram: 0
[16:06:16.417] <TB1> INFO: frame (failed synchr.): 0
[16:06:16.417] <TB1> INFO: idle data (no TBM trl): 0
[16:06:16.417] <TB1> INFO: no data (only TBM hdr): 0
[16:06:16.417] <TB1> INFO: TBM errors: 0
[16:06:16.417] <TB1> INFO: flawed TBM headers: 0
[16:06:16.417] <TB1> INFO: flawed TBM trailers: 0
[16:06:16.417] <TB1> INFO: event ID mismatches: 0
[16:06:16.417] <TB1> INFO: ROC errors: 0
[16:06:16.417] <TB1> INFO: missing ROC header(s): 0
[16:06:16.417] <TB1> INFO: misplaced readback start: 0
[16:06:16.417] <TB1> INFO: Pixel decoding errors: 0
[16:06:16.417] <TB1> INFO: pixel data incomplete: 0
[16:06:16.417] <TB1> INFO: pixel address: 0
[16:06:16.417] <TB1> INFO: pulse height fill bit: 0
[16:06:16.417] <TB1> INFO: buffer corruption: 0
[16:06:16.427] <TB1> INFO: readReadbackCal: /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C0.dat .. /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C15.dat
[16:06:16.755] <TB1> INFO: ######################################################################
[16:06:16.755] <TB1> INFO: PixTestReadback::doTest()
[16:06:16.755] <TB1> INFO: ######################################################################
[16:06:16.755] <TB1> INFO: ----------------------------------------------------------------------
[16:06:16.755] <TB1> INFO: PixTestReadback::CalibrateVd()
[16:06:16.755] <TB1> INFO: ----------------------------------------------------------------------
[16:06:26.216] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C0.dat
[16:06:26.221] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C1.dat
[16:06:26.227] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C2.dat
[16:06:26.233] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C3.dat
[16:06:26.238] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C4.dat
[16:06:26.243] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C5.dat
[16:06:26.248] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C6.dat
[16:06:26.255] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C7.dat
[16:06:26.260] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C8.dat
[16:06:26.267] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C9.dat
[16:06:26.272] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C10.dat
[16:06:26.277] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C11.dat
[16:06:26.282] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C12.dat
[16:06:26.287] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C13.dat
[16:06:26.292] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C14.dat
[16:06:26.297] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C15.dat
[16:06:26.326] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[16:06:26.326] <TB1> INFO: ----------------------------------------------------------------------
[16:06:26.326] <TB1> INFO: PixTestReadback::CalibrateVa()
[16:06:26.326] <TB1> INFO: ----------------------------------------------------------------------
[16:06:35.830] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C0.dat
[16:06:35.835] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C1.dat
[16:06:35.843] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C2.dat
[16:06:35.850] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C3.dat
[16:06:35.854] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C4.dat
[16:06:35.860] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C5.dat
[16:06:35.866] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C6.dat
[16:06:35.871] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C7.dat
[16:06:35.876] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C8.dat
[16:06:35.881] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C9.dat
[16:06:35.886] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C10.dat
[16:06:35.891] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C11.dat
[16:06:35.897] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C12.dat
[16:06:35.903] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C13.dat
[16:06:35.908] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C14.dat
[16:06:35.916] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C15.dat
[16:06:35.945] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[16:06:35.945] <TB1> INFO: ----------------------------------------------------------------------
[16:06:35.945] <TB1> INFO: PixTestReadback::readbackVbg()
[16:06:35.945] <TB1> INFO: ----------------------------------------------------------------------
[16:06:43.227] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[16:06:43.227] <TB1> INFO: ----------------------------------------------------------------------
[16:06:43.227] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[16:06:43.227] <TB1> INFO: ----------------------------------------------------------------------
[16:06:43.227] <TB1> INFO: Vbg will be calibrated using Vd calibration
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 148.2calibrated Vbg = 1.23551 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156.3calibrated Vbg = 1.22738 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 148.1calibrated Vbg = 1.23631 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 156.3calibrated Vbg = 1.24203 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 159.3calibrated Vbg = 1.24995 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 156.3calibrated Vbg = 1.24769 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 155.8calibrated Vbg = 1.2481 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 154calibrated Vbg = 1.24635 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 156.5calibrated Vbg = 1.25152 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 150calibrated Vbg = 1.24877 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 154.6calibrated Vbg = 1.24701 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 153calibrated Vbg = 1.24049 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 152.6calibrated Vbg = 1.23574 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 156calibrated Vbg = 1.23299 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 160.8calibrated Vbg = 1.2379 :::*/*/*/*/
[16:06:43.227] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 151.3calibrated Vbg = 1.2338 :::*/*/*/*/
[16:06:43.229] <TB1> INFO: ----------------------------------------------------------------------
[16:06:43.229] <TB1> INFO: PixTestReadback::CalibrateIa()
[16:06:43.229] <TB1> INFO: ----------------------------------------------------------------------
[16:09:18.415] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C0.dat
[16:09:18.441] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C1.dat
[16:09:18.446] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C2.dat
[16:09:18.452] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C3.dat
[16:09:18.460] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C4.dat
[16:09:18.467] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C5.dat
[16:09:18.472] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C6.dat
[16:09:18.477] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C7.dat
[16:09:18.482] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C8.dat
[16:09:18.488] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C9.dat
[16:09:18.493] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C10.dat
[16:09:18.499] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C11.dat
[16:09:18.504] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C12.dat
[16:09:18.509] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C13.dat
[16:09:18.514] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C14.dat
[16:09:18.519] <TB1> INFO: write readback calibration parameters into /home/production/dataCH/M2288_FullQualification_2016-08-08_09h46m_1470642396//004_FulltestPxar_p17//readbackCal_C15.dat
[16:09:18.545] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[16:09:18.545] <TB1> INFO: PixTestReadback::doTest() done
[16:09:18.545] <TB1> INFO: Decoding statistics:
[16:09:18.545] <TB1> INFO: General information:
[16:09:18.545] <TB1> INFO: 16bit words read: 1024
[16:09:18.545] <TB1> INFO: valid events total: 128
[16:09:18.545] <TB1> INFO: empty events: 128
[16:09:18.545] <TB1> INFO: valid events with pixels: 0
[16:09:18.545] <TB1> INFO: valid pixel hits: 0
[16:09:18.545] <TB1> INFO: Event errors: 0
[16:09:18.545] <TB1> INFO: start marker: 0
[16:09:18.545] <TB1> INFO: stop marker: 0
[16:09:18.545] <TB1> INFO: overflow: 0
[16:09:18.545] <TB1> INFO: invalid 5bit words: 0
[16:09:18.545] <TB1> INFO: invalid XOR eye diagram: 0
[16:09:18.545] <TB1> INFO: frame (failed synchr.): 0
[16:09:18.545] <TB1> INFO: idle data (no TBM trl): 0
[16:09:18.545] <TB1> INFO: no data (only TBM hdr): 0
[16:09:18.545] <TB1> INFO: TBM errors: 0
[16:09:18.545] <TB1> INFO: flawed TBM headers: 0
[16:09:18.545] <TB1> INFO: flawed TBM trailers: 0
[16:09:18.545] <TB1> INFO: event ID mismatches: 0
[16:09:18.545] <TB1> INFO: ROC errors: 0
[16:09:18.545] <TB1> INFO: missing ROC header(s): 0
[16:09:18.545] <TB1> INFO: misplaced readback start: 0
[16:09:18.545] <TB1> INFO: Pixel decoding errors: 0
[16:09:18.545] <TB1> INFO: pixel data incomplete: 0
[16:09:18.546] <TB1> INFO: pixel address: 0
[16:09:18.546] <TB1> INFO: pulse height fill bit: 0
[16:09:18.546] <TB1> INFO: buffer corruption: 0
[16:09:18.568] <TB1> INFO: Decoding statistics:
[16:09:18.568] <TB1> INFO: General information:
[16:09:18.568] <TB1> INFO: 16bit words read: 2755364
[16:09:18.568] <TB1> INFO: valid events total: 176768
[16:09:18.568] <TB1> INFO: empty events: 7863
[16:09:18.568] <TB1> INFO: valid events with pixels: 168905
[16:09:18.568] <TB1> INFO: valid pixel hits: 668054
[16:09:18.568] <TB1> INFO: Event errors: 0
[16:09:18.568] <TB1> INFO: start marker: 0
[16:09:18.568] <TB1> INFO: stop marker: 0
[16:09:18.568] <TB1> INFO: overflow: 0
[16:09:18.568] <TB1> INFO: invalid 5bit words: 0
[16:09:18.568] <TB1> INFO: invalid XOR eye diagram: 0
[16:09:18.568] <TB1> INFO: frame (failed synchr.): 0
[16:09:18.568] <TB1> INFO: idle data (no TBM trl): 0
[16:09:18.568] <TB1> INFO: no data (only TBM hdr): 0
[16:09:18.568] <TB1> INFO: TBM errors: 0
[16:09:18.568] <TB1> INFO: flawed TBM headers: 0
[16:09:18.568] <TB1> INFO: flawed TBM trailers: 0
[16:09:18.568] <TB1> INFO: event ID mismatches: 0
[16:09:18.568] <TB1> INFO: ROC errors: 0
[16:09:18.568] <TB1> INFO: missing ROC header(s): 0
[16:09:18.568] <TB1> INFO: misplaced readback start: 0
[16:09:18.568] <TB1> INFO: Pixel decoding errors: 0
[16:09:18.568] <TB1> INFO: pixel data incomplete: 0
[16:09:18.568] <TB1> INFO: pixel address: 0
[16:09:18.568] <TB1> INFO: pulse height fill bit: 0
[16:09:18.568] <TB1> INFO: buffer corruption: 0
[16:09:18.568] <TB1> INFO: enter test to run
[16:09:18.568] <TB1> INFO: test: exit no parameter change
[16:09:18.610] <TB1> QUIET: Connection to board 154 closed.
[16:09:18.690] <TB1> INFO: pXar: this is the end, my friend