[13:42:11.203] <TB3> INFO: *** Welcome to pxar ***
[13:42:11.203] <TB3> INFO: *** Today: 2016/09/19
[13:42:11.269] <TB3> INFO: *** Version: f5d3-dirty
[13:42:11.269] <TB3> INFO: readRocDacs: /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//dacParameters35_C15.dat
[13:42:11.270] <TB3> INFO: readTbmDacs: /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//tbmParameters_C0b.dat
[13:42:11.270] <TB3> INFO: readMaskFile: /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//defaultMaskFile.dat
[13:42:11.270] <TB3> INFO: readTrimFile: /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//trimParameters35_C15.dat
[13:42:11.349] <TB3> INFO: clk: 4
[13:42:11.349] <TB3> INFO: ctr: 4
[13:42:11.349] <TB3> INFO: sda: 19
[13:42:11.349] <TB3> INFO: tin: 9
[13:42:11.349] <TB3> INFO: level: 15
[13:42:11.349] <TB3> INFO: triggerdelay: 0
[13:42:11.349] <TB3> QUIET: Instanciating API for pxar v2.7.5+30~g833b08f
[13:42:11.349] <TB3> INFO: Log level: INFO
[13:42:11.361] <TB3> INFO: Found DTB DTB_WWV6Z5
[13:42:11.370] <TB3> QUIET: Connection to board DTB_WWV6Z5 opened.
[13:42:11.372] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 121
HW version: DTB1.2
FW version: 4.4
SW version: 4.6
Options:
USB id: DTB_WWV6Z5
MAC address: 40D855118079
Hostname: pixelDTB121
Comment:
------------------------------------------------------
[13:42:11.374] <TB3> INFO: RPC call hashes of host and DTB match: 484264910
[13:42:12.918] <TB3> INFO: DUT info:
[13:42:12.918] <TB3> INFO: The DUT currently contains the following objects:
[13:42:12.918] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:42:12.918] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:42:12.918] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:42:12.918] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:42:12.918] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:12.918] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:42:13.319] <TB3> INFO: enter 'restricted' command line mode
[13:42:13.319] <TB3> INFO: enter test to run
[13:42:13.319] <TB3> INFO: test: delay setting parameters: ->5<-
[13:42:13.319] <TB3> INFO: delay test by 5 seconds...
[13:42:18.319] <TB3> INFO: enter test to run
[13:42:18.319] <TB3> INFO: test: Xray no parameter change
[13:42:18.319] <TB3> INFO: running: xray
[13:42:18.319] <TB3> INFO: readGainPedestalParameters /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2318_XrayQualification_2016-09-19_15h21m_1474291317//005_HRData_150//phCalibrationFitErr35_C15.dat
[13:42:18.504] <TB3> INFO: ######################################################################
[13:42:18.504] <TB3> INFO: PixTestXray::doTest()
[13:42:18.504] <TB3> INFO: ######################################################################
[13:42:18.504] <TB3> INFO: ----------------------------------------------------------------------
[13:42:18.504] <TB3> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:42:18.504] <TB3> INFO: ----------------------------------------------------------------------
[13:42:19.233] <TB3> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:42:23.164] <TB3> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[13:42:52.853] <TB3> INFO: Resuming triggers.
[13:42:56.789] <TB3> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:43:26.884] <TB3> INFO: Resuming triggers.
[13:43:30.823] <TB3> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:43:59.855] <TB3> INFO: Resuming triggers.
[13:44:03.792] <TB3> INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[13:44:33.412] <TB3> INFO: Resuming triggers.
[13:44:37.346] <TB3> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:45:06.789] <TB3> INFO: Resuming triggers.
[13:45:10.728] <TB3> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:45:11.859] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 32 readouts!
[13:45:11.859] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a332 8000 4070 1b 2268 601 2065 4070 4071 153 264d 280 2469 4071 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32c 80b0 4070 95 2240 259 2a4a 80c 246c 4070 8d 2a4f 413 2068 45b 2262 4070 121 224c 4071 fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32d 80c0 4070 0 2442 4070 4db 2468 701 2641 4070 160 2041 751 264f 4070 509 2447 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32e 8000 4070 219 2266 2d4 2660 4070 4070 4070 305 2445 30c 2a49 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a32f 8040 4072 98 2a21 541 266a 4072 4072 4072 2e0 2a83 fff 2fff fff 2fff fff 2fff e000 c000
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a330 80b0 4071 4071 35a 2244 4071 51d 2846 81c 2240 4071 492 2641 fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:45:11.885] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a331 80c0 4071 482 2468 4071 4071 320 2641 6da 206b 4071 159 224e 71a 2281 fff 2fff fff 2fff fff 2fff e000 c000
[13:45:39.902] <TB3> INFO: Resuming triggers.
[13:45:43.842] <TB3> INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:46:13.422] <TB3> INFO: Resuming triggers.
[13:46:17.361] <TB3> INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:46:37.529] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L507> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a315 80c0 4070 d1 2a4c 4070 254 2a44 294 2849 619 284f 603 264f 655 2062 743 2062 4060 860 2640 4070 550 2643 fff 2fff fff 2fff fff 2fff e000 c000
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a30f 8040 4072 4072 6da 2049 4072 4072 111 2a45 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a310 80b0 4071 4071 4 2447 25b 284f 4071 99 2645 4071 611 2245 fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a311 80c0 4071 10a 2a42 45a 2249 494 284d 4071 811 244f 844 2640 4071 4071 58 264a cc 2843 fff 2fff fff 2fff fff 2fff e000 c000
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a312 8000 4070 64b 2a4c 744 2643 4070 9 244f 7f0 2000 62d 2210 64d 280d 446 27f9 e000 c000
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a313 8040 4070 51 224f 352 2681 4071 4070 59 2846 e2 286b 4071 d3 2865 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:46:37.530] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a314 80b0 4070 90 2426 205 286f 559 2a68 4070 1a 286d 4a 2661 8a 244f 619 262f 68a 224d 4070 61 2a4e 4070 820 2649 fff 2fff fff 2fff fff 2fff e000 c000
[13:46:47.106] <TB3> INFO: Resuming triggers.
[13:46:51.044] <TB3> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:47:19.929] <TB3> INFO: Resuming triggers.
[13:47:23.863] <TB3> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:47:53.105] <TB3> INFO: Resuming triggers.
[13:47:57.037] <TB3> INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:48:26.112] <TB3> INFO: Resuming triggers.
[13:48:30.062] <TB3> INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:48:59.317] <TB3> INFO: Resuming triggers.
[13:49:03.250] <TB3> INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:49:32.817] <TB3> INFO: Resuming triggers.
[13:49:36.749] <TB3> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:50:05.838] <TB3> INFO: Resuming triggers.
[13:50:09.769] <TB3> INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:50:39.122] <TB3> INFO: Resuming triggers.
[13:50:43.053] <TB3> INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[13:51:12.147] <TB3> INFO: Resuming triggers.
[13:51:16.079] <TB3> INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:51:19.004] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L507> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a7 8041 4060 301 2a86 759 2043 4070 4070 552 222d 4071 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a1 80c0 4071 118 2829 344 2a62 4071 245 224a 4071 4d9 2a4c 4071 90 2449 fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a2 8000 4070 714 2847 4070 4071 6d3 2a4f 4071 159 2045 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a3 8040 4070 25c 2448 292 2463 4071 69b 244e 4070 682 2464 4071 80b 2865 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a4 80b0 4070 4070 1a 2449 c5 266f 2e0 282a 7f0 2004 29 2154 64d 2415 482 26d1 a66 27f8 112 2446 315 2665 fff 2fff fff 2fff e000 c000
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a5 80c0 4070 818 2a42 4070 4070 4070 755 2a4f fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[13:51:19.004] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a6 8000 4070 4070 4070 4070 158 2462 503 2068 6dd 2662 819 264c 819 2a61 fff 2fff fff 2fff e000 c000
[13:51:45.204] <TB3> INFO: Resuming triggers.
[13:51:49.135] <TB3> INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:52:18.522] <TB3> INFO: Resuming triggers.
[13:52:22.453] <TB3> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:52:52.033] <TB3> INFO: Resuming triggers.
[13:52:55.966] <TB3> INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:53:25.725] <TB3> INFO: Resuming triggers.
[13:53:29.659] <TB3> INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:53:59.708] <TB3> INFO: Resuming triggers.
[13:54:03.636] <TB3> INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:54:33.483] <TB3> INFO: Resuming triggers.
[13:54:37.415] <TB3> INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:55:07.057] <TB3> INFO: Resuming triggers.
[13:55:10.985] <TB3> INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:55:40.327] <TB3> INFO: Resuming triggers.
[13:55:44.256] <TB3> INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:56:12.398] <TB3> INFO: Resuming triggers.
[13:56:14.098] <TB3> INFO: data taking finished, elapsed time: 100 seconds.
[13:56:26.840] <TB3> INFO: PixTest:: pg_setup set to default.
[13:56:26.841] <TB3> INFO: PixTestXray::doPhRun() done
[13:56:26.841] <TB3> INFO: PixTestXray::doTest() done
[13:56:27.025] <TB3> INFO: enter test to run
[13:56:27.025] <TB3> INFO: test: no parameter change
[13:56:27.283] <TB3> QUIET: Connection to board 121 closed.
[13:56:27.365] <TB3> INFO: pXar: this is the end, my friend