[08:31:50.692] <TB1> INFO: *** Welcome to pxar ***
[08:31:50.692] <TB1> INFO: *** Today: 2016/09/20
[08:31:50.761] <TB1> INFO: *** Version: f5d3-dirty
[08:31:50.761] <TB1> INFO: readRocDacs: /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//dacParameters35_C15.dat
[08:31:50.761] <TB1> INFO: readTbmDacs: /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//tbmParameters_C0b.dat
[08:31:50.762] <TB1> INFO: readMaskFile: /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//defaultMaskFile.dat
[08:31:50.762] <TB1> INFO: readTrimFile: /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//trimParameters35_C15.dat
[08:31:50.836] <TB1> INFO: clk: 4
[08:31:50.837] <TB1> INFO: ctr: 4
[08:31:50.837] <TB1> INFO: sda: 19
[08:31:50.837] <TB1> INFO: tin: 9
[08:31:50.837] <TB1> INFO: level: 15
[08:31:50.837] <TB1> INFO: triggerdelay: 0
[08:31:50.837] <TB1> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[08:31:50.837] <TB1> INFO: Log level: INFO
[08:31:50.850] <TB1> INFO: Found DTB DTB_WWXTQT
[08:31:50.859] <TB1> QUIET: Connection to board DTB_WWXTQT opened.
[08:31:50.861] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 147
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWXTQT
MAC address: 40D855118093
Hostname: pixelDTB147
Comment:
------------------------------------------------------
[08:31:50.863] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[08:31:52.407] <TB1> INFO: DUT info:
[08:31:52.408] <TB1> INFO: The DUT currently contains the following objects:
[08:31:52.408] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[08:31:52.408] <TB1> INFO: TBM Core alpha (0): 7 registers set
[08:31:52.408] <TB1> INFO: TBM Core beta (1): 7 registers set
[08:31:52.408] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[08:31:52.408] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.408] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[08:31:52.809] <TB1> INFO: enter 'restricted' command line mode
[08:31:52.809] <TB1> INFO: enter test to run
[08:31:52.809] <TB1> INFO: test: delay setting parameters: ->5<-
[08:31:52.809] <TB1> INFO: delay test by 5 seconds...
[08:31:57.809] <TB1> INFO: enter test to run
[08:31:57.810] <TB1> INFO: test: Xray no parameter change
[08:31:57.810] <TB1> INFO: running: xray
[08:31:57.810] <TB1> INFO: readGainPedestalParameters /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2317_XrayQualification_2016-09-20_10h14m_1474359284//005_HRData_150//phCalibrationFitErr35_C15.dat
[08:31:57.941] <TB1> INFO: ######################################################################
[08:31:57.941] <TB1> INFO: PixTestXray::doTest()
[08:31:57.941] <TB1> INFO: ######################################################################
[08:31:57.941] <TB1> INFO: ----------------------------------------------------------------------
[08:31:57.941] <TB1> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[08:31:57.941] <TB1> INFO: ----------------------------------------------------------------------
[08:31:58.666] <TB1> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[08:32:02.652] <TB1> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[08:32:27.178] <TB1> INFO: Resuming triggers.
[08:32:31.176] <TB1> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[08:32:57.810] <TB1> INFO: Resuming triggers.
[08:33:01.806] <TB1> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[08:33:28.829] <TB1> INFO: Resuming triggers.
[08:33:32.823] <TB1> INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[08:33:59.874] <TB1> INFO: Resuming triggers.
[08:34:03.867] <TB1> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[08:34:30.235] <TB1> INFO: Resuming triggers.
[08:34:34.228] <TB1> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[08:35:01.146] <TB1> INFO: Resuming triggers.
[08:35:05.148] <TB1> INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[08:35:32.870] <TB1> INFO: Resuming triggers.
[08:35:36.855] <TB1> INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[08:36:04.187] <TB1> INFO: Resuming triggers.
[08:36:08.171] <TB1> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[08:36:25.628] <TB1> WARNING: Channel 1 ROC 3: Readback start marker after 1 readouts!
[08:36:25.628] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[08:36:25.628] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:36:25.628] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1b3 8040 41c0 109 202c 2d4 2262 719 242f 740 2827 41c1 204 266a 45b 2681 618 2447 600 2a85 40c0 a0 2440 41c1 8c 2445 8c 2049 21d 208c 205 2880 40c 2668 64d 2465 64d 268b e000 c000
[08:36:25.628] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1ad 80c0 40c0 21 2288 30a 2865 549 288a 41c0 21 20a4 b 2686 360 2468 41c0 cc 2444 101 2a4b 318 244f 64a 204d 41c0 a 2449 9d 286b 11b 206d e000 c000
[08:36:25.628] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1ae 8000 40c0 349 264c 41c0 308 2245 520 284d 548 2449 41c0 143 224b 720 2a44 41c0 d5 2065 309 2462 30d 266f 75b 2283 e000 c000
[08:36:25.628] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1af 8040 40c2 108 202c 761 2065 41c2 415 2a26 418 2225 483 248f 643 2440 41c2 658 282d 6c3 2449 41c2 11a 224a 219 2867 68b 2865 e000 c000
[08:36:25.629] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1b0 80b0 41c0 205 284f 613 2480 814 2846 41c0 80a 286a 41c0 41c3 8e0 2164 de4 2114 c4c 2988 80c 2970 41c0 850 244d 852 262d e000 c000
[08:36:25.629] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1b1 80c0 40c1 e2 246c c4 2a4f 6c8 202e 40c1 20b 2a4f 81b 2069 41c1 c9 2063 142 264d 51c 204b 6ca 2a43 41c1 691 264f e000 c000
[08:36:25.629] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1b2 8000 40c0 48a 284f 4ca 264f 505 2067 504 2065 41c0 512 2028 618 284e 614 204d 41c1 55 2841 151 2482 659 224f 41c1 61b 288c 75b 2a6b e000 c000
[08:36:36.750] <TB1> INFO: Resuming triggers.
[08:36:40.734] <TB1> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[08:37:07.915] <TB1> INFO: Resuming triggers.
[08:37:11.892] <TB1> INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[08:37:38.720] <TB1> INFO: Resuming triggers.
[08:37:42.698] <TB1> INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[08:38:09.095] <TB1> INFO: Resuming triggers.
[08:38:13.068] <TB1> INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[08:38:39.864] <TB1> INFO: Resuming triggers.
[08:38:43.838] <TB1> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[08:39:10.822] <TB1> INFO: Resuming triggers.
[08:39:14.794] <TB1> INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[08:39:41.306] <TB1> INFO: Resuming triggers.
[08:39:45.278] <TB1> INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[08:40:11.250] <TB1> INFO: Resuming triggers.
[08:40:15.218] <TB1> INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[08:40:42.234] <TB1> INFO: Resuming triggers.
[08:40:46.202] <TB1> INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[08:41:13.010] <TB1> INFO: Resuming triggers.
[08:41:16.979] <TB1> INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[08:41:34.353] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 3 Number of ROCs (5) != Token Chain Length (4)
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a332 8001 41c0 4c9 2845 649 2a64 698 284d 815 2a4c 850 2027 41c0 2d4 2645 41c1 4c3 2a41 41c1 1d 2a63 e000 c000
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32c 80b1 41c0 4dc 2a2d 65d 224c 41c0 683 266d 75b 222f 41c0 55 224f 41c1 e000 c000
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32d 80c1 41c0 9c 2460 859 2047 849 2462 41c0 99 2449 103 2661 41c0 41c1 e000 c000
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32e 8001 41c0 219 2846 41c0 95 224b 41c0 11c 2442 121 2664 312 262d 41c1 e000 c000
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32f 8041 41c2 41c2 5ea 29b5 30 2c04 41c1 21c 242c 618 2a2f 41c2 4a0 2842 6c0 244a 41c2 249 264d e000 c000
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a330 80b1 41c1 51 284f 299 2260 44a 2a41 41c1 45 2247 11a 2444 119 2a62 41c1 2da 2a4d 821 264f 41c1 118 2048 201 2467 31d 2042 452 2665 e000 c000
[08:41:34.353] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a331 80c1 41c1 60d 2848 60d 2460 41c1 549 284f 41c1 641 2469 84b 286d 41c1 e000 c000
[08:41:42.410] <TB1> INFO: Resuming triggers.
[08:41:46.378] <TB1> INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[08:42:11.305] <TB1> INFO: Resuming triggers.
[08:42:15.268] <TB1> INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[08:42:40.441] <TB1> INFO: Resuming triggers.
[08:42:44.404] <TB1> INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[08:43:10.925] <TB1> INFO: Resuming triggers.
[08:43:14.891] <TB1> INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[08:43:40.948] <TB1> INFO: Resuming triggers.
[08:43:44.910] <TB1> INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[08:44:11.866] <TB1> INFO: Resuming triggers.
[08:44:15.830] <TB1> INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[08:44:41.587] <TB1> INFO: Resuming triggers.
[08:44:42.244] <TB1> INFO: data taking finished, elapsed time: 100 seconds.
[08:44:46.970] <TB1> INFO: PixTest:: pg_setup set to default.
[08:44:46.971] <TB1> INFO: PixTestXray::doPhRun() done
[08:44:46.971] <TB1> INFO: PixTestXray::doTest() done
[08:44:47.157] <TB1> INFO: enter test to run
[08:44:47.157] <TB1> INFO: test: no parameter change
[08:44:47.393] <TB1> QUIET: Connection to board 147 closed.
[08:44:47.478] <TB1> INFO: pXar: this is the end, my friend