[10:16:50.853] <TB3> INFO: *** Welcome to pxar ***
[10:16:50.853] <TB3> INFO: *** Today: 2015/09/10
[10:16:50.853] <TB3> INFO: readRocDacs: /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//dacParameters35_C15.dat
[10:16:50.854] <TB3> INFO: readTbmDacs: /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//tbmParameters_C0b.dat
[10:16:50.854] <TB3> INFO: readMaskFile: /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//defaultMaskFile.dat
[10:16:50.854] <TB3> INFO: readTrimFile: /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//trimParameters35_C15.dat
[10:16:50.946] <TB3> INFO: clk: 4
[10:16:50.946] <TB3> INFO: ctr: 4
[10:16:50.946] <TB3> INFO: sda: 19
[10:16:50.946] <TB3> INFO: tin: 9
[10:16:50.946] <TB3> INFO: level: 15
[10:16:50.946] <TB3> INFO: triggerdelay: 0
[10:16:50.947] <TB3> QUIET: Instanciating API for pxar prod-10+24~g09f6d2c
[10:16:50.947] <TB3> INFO: Log level: INFO
[10:16:51.958] <TB3> INFO: Found DTB DTB_WWV6Z5
[10:16:54.970] <TB3> QUIET: Connection to board DTB_WWV6Z5 opened.
[10:16:54.973] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 121
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WWV6Z5
MAC address: 40D855118079
Hostname: pixelDTB121
Comment:
------------------------------------------------------
[10:16:54.976] <TB3> INFO: RPC call hashes of host and DTB match: 398089610
[10:16:56.515] <TB3> INFO: DUT info:
[10:16:56.515] <TB3> INFO: The DUT currently contains the following objects:
[10:16:56.515] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:16:56.515] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:16:56.515] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:16:56.515] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:16:56.515] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.515] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.515] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.516] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:16:56.917] <TB3> INFO: enter 'restricted' command line mode
[10:16:56.917] <TB3> INFO: enter test to run
[10:16:56.917] <TB3> INFO: test: delay setting parameters: ->5<-
[10:16:56.917] <TB3> INFO: delay test by 5 seconds...
[10:17:01.917] <TB3> INFO: enter test to run
[10:17:01.917] <TB3> INFO: test: Xray no parameter change
[10:17:01.918] <TB3> INFO: running: xray
[10:17:01.918] <TB3> INFO: readGainPedestalParameters /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2097_XrayQualification_2015-09-10_11h57m_1441879041//004_HRData_150//phCalibrationFitErr35_C15.dat
[10:17:02.071] <TB3> INFO: ######################################################################
[10:17:02.071] <TB3> INFO: PixTestXray::doTest()
[10:17:02.071] <TB3> INFO: ######################################################################
[10:17:02.071] <TB3> INFO: ----------------------------------------------------------------------
[10:17:02.071] <TB3> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:17:02.071] <TB3> INFO: ----------------------------------------------------------------------
[10:17:03.038] <TB3> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:17:06.735] <TB3> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[10:17:35.207] <TB3> INFO: Resuming triggers.
[10:17:38.917] <TB3> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[10:18:07.063] <TB3> INFO: Resuming triggers.
[10:18:10.777] <TB3> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:18:39.745] <TB3> INFO: Resuming triggers.
[10:18:43.456] <TB3> INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[10:19:12.344] <TB3> INFO: Resuming triggers.
[10:19:16.057] <TB3> INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[10:19:44.990] <TB3> INFO: Resuming triggers.
[10:19:48.702] <TB3> INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:20:19.695] <TB3> INFO: Resuming triggers.
[10:20:23.409] <TB3> INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[10:20:52.941] <TB3> INFO: Resuming triggers.
[10:20:56.652] <TB3> INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[10:21:26.144] <TB3> INFO: Resuming triggers.
[10:21:29.855] <TB3> INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:21:58.939] <TB3> INFO: Resuming triggers.
[10:22:02.651] <TB3> INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[10:22:31.680] <TB3> INFO: Resuming triggers.
[10:22:35.391] <TB3> INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:23:05.011] <TB3> INFO: Resuming triggers.
[10:23:08.721] <TB3> INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:23:39.882] <TB3> INFO: Resuming triggers.
[10:23:43.594] <TB3> INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[10:24:14.585] <TB3> INFO: Resuming triggers.
[10:24:18.295] <TB3> INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[10:24:47.803] <TB3> INFO: Resuming triggers.
[10:24:51.513] <TB3> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:25:19.947] <TB3> INFO: Resuming triggers.
[10:25:23.660] <TB3> INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:25:52.388] <TB3> INFO: Resuming triggers.
[10:25:56.097] <TB3> INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:26:24.855] <TB3> INFO: Resuming triggers.
[10:26:28.562] <TB3> INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:26:55.998] <TB3> INFO: Resuming triggers.
[10:26:59.708] <TB3> INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:27:29.625] <TB3> INFO: Resuming triggers.
[10:27:33.334] <TB3> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[10:28:04.147] <TB3> INFO: Resuming triggers.
[10:28:07.858] <TB3> INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[10:28:37.604] <TB3> INFO: Resuming triggers.
[10:28:41.311] <TB3> INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:29:11.442] <TB3> INFO: Resuming triggers.
[10:29:15.153] <TB3> INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[10:29:43.084] <TB3> INFO: Resuming triggers.
[10:29:46.793] <TB3> INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:29:55.707] <TB3> WARNING: Channel 2 ROC 3: Readback start marker after 2 readouts!
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a233 8040 4e18 162 2844 28c 204d 310 2065 305 2a82 340 264d 689 2463 4e18 542 2a4c 61a 2044 60c 224e 753 242f 4e18 1b 2463 441 2263 848 2829 4e18 c4 2a6f 290 2869 685 2662 854 2a43 e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a22d 80c0 4e18 812 2241 4e18 415 2a4f 4e18 d9 2265 209 2a41 403 2867 50b 2864 759 244c 4e18 53 2481 14d 2448 2cd 286d 312 2268 615 266f e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a22e 8000 4e18 4e1a 611 262e 700 2843 858 2a48 4e1a 9c 2661 c5 202f c1 2a4f 35b 206f 69b 2480 680 2a4f 71c 2a49 4e1a cc 224f dd 2287 2d3 2880 65d 264f e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a22f 8040 4e1a 55a 2265 812 2041 4e19 c0 2840 351 204f 81b 246f 4e19 850 2a4c 4e19 319 2082 318 2880 35c 2a4f e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a230 80b0 4e19 818 2262 4e18 649 284e 4e18 4e1b 286f 543 2865 641 286c 4e18 451 2668 714 204d e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a231 80c0 4e18 60 2644 290 2042 64b 264f 750 224c 4e18 24b 2041 4e19 58 2064 14a 246c 30c 2644 648 2468 751 2845 749 2264 84a 282d 4e19 15 224d e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a232 8000 4e18 604 2628 4e19 d5 2a4c 14a 2081 14a 22a0 2cb 286f 482 2a2c 51d 2a6e 844 264f 4e18 4c8 264c 6da 284f 4e19 348 2645 e000 c000
[10:29:55.707] <TB3> WARNING: Channel 2 ROC 3: Readback start marker after 14 readouts!
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a241 80c0 4e18 e1 2a4d 452 2448 4e18 460 204c 4e19 819 284f 4e19 14b 244e 41b 264d fff 2fff e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a23b 8040 4e18 35b 2a69 753 2a4c 4e18 45 2864 315 2461 75d 2048 75d 224f 4e18 103 246a 34b 2068 44d 2a4f 4e19 e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a23c 80b0 4e18 28a 242c 512 222f 4e18 e0 2a69 2c3 246e 2c3 2664 408 2869 4e18 4e18 15 2068 551 2243 658 2a4f e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a23d 80c0 4e18 315 204c 4e18 11 2241 15c 2861 551 264e 6c5 2042 4e18 143 2488 6cc 222f 80d 2083 4e18 41b 2649 55d 262d e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a23e 8000 4e18 71a 2844 4e1a 653 2464 4e1a 489 202d 55a 2265 4e1a c8 2644 50d 2a4e 55c 2441 759 2461 e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a23f 8040 4e1a 0 284a 3 264d 650 284a 713 224c 4e19 c8 2847 4e19 120 2a88 654 2442 692 2a85 4e19 31a 286d fff 2fff e000 c000
[10:29:55.707] <TB3> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a240 80b0 4e19 4 244a 114 2649 4e18 50b 2068 70c 260c 4e18 35d 2269 4e18 d 2461 45 2465 8c 2465 160 244f 514 2847 e000 c000
[10:30:15.540] <TB3> INFO: Resuming triggers.
[10:30:19.249] <TB3> INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:30:47.726] <TB3> INFO: Resuming triggers.
[10:30:51.432] <TB3> INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[10:31:20.807] <TB3> INFO: Resuming triggers.
[10:31:24.428] <TB3> INFO: data taking finished, elapsed time: 100 seconds.
[10:31:52.970] <TB3> INFO: PixTest:: pg_setup set to default.
[10:31:52.971] <TB3> INFO: PixTestXray::doPhRun() done
[10:31:52.971] <TB3> INFO: PixTestXray::doTest() done
[10:31:53.164] <TB3> INFO: enter test to run
[10:31:53.164] <TB3> INFO: test: no parameter change
[10:31:53.343] <TB3> QUIET: Connection to board 121 closed.
[10:31:53.422] <TB3> INFO: pXar: this is the end, my friend