[09:06:39.064] <TB1> INFO: *** Welcome to pxar ***
[09:06:39.064] <TB1> INFO: *** Today: 2016/02/24
[09:06:39.436] <TB1> INFO: *** Version: 9751
[09:06:39.436] <TB1> INFO: readRocDacs: /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//dacParameters35_C0.dat .. /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//dacParameters35_C15.dat
[09:06:39.437] <TB1> INFO: readTbmDacs: /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//tbmParameters_C0a.dat .. /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//tbmParameters_C0b.dat
[09:06:39.437] <TB1> INFO: readMaskFile: /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//defaultMaskFile.dat
[09:06:39.437] <TB1> INFO: readTrimFile: /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//trimParameters35_C0.dat .. /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//trimParameters35_C15.dat
[09:06:39.510] <TB1> INFO: clk: 4
[09:06:39.510] <TB1> INFO: ctr: 4
[09:06:39.510] <TB1> INFO: sda: 19
[09:06:39.510] <TB1> INFO: tin: 9
[09:06:39.510] <TB1> INFO: level: 15
[09:06:39.510] <TB1> INFO: triggerdelay: 0
[09:06:39.510] <TB1> QUIET: Instanciating API for pxar v2.7.5+30~g833b08f
[09:06:39.510] <TB1> INFO: Log level: INFO
[09:06:39.524] <TB1> INFO: Found DTB DTB_WWXTQT
[09:06:39.534] <TB1> QUIET: Connection to board DTB_WWXTQT opened.
[09:06:39.536] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 147
HW version: DTB1.2
FW version: 4.4
SW version: 4.6
Options:
USB id: DTB_WWXTQT
MAC address: 40D855118093
Hostname: pixelDTB147
Comment:
------------------------------------------------------
[09:06:39.538] <TB1> INFO: RPC call hashes of host and DTB match: 484264910
[09:06:41.083] <TB1> INFO: DUT info:
[09:06:41.083] <TB1> INFO: The DUT currently contains the following objects:
[09:06:41.083] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:06:41.083] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:06:41.084] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:06:41.084] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:06:41.084] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.084] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:41.485] <TB1> INFO: enter 'restricted' command line mode
[09:06:41.485] <TB1> INFO: enter test to run
[09:06:41.486] <TB1> INFO: test: delay setting parameters: ->5<-
[09:06:41.486] <TB1> INFO: delay test by 5 seconds...
[09:06:46.486] <TB1> INFO: enter test to run
[09:06:46.486] <TB1> INFO: test: Xray no parameter change
[09:06:46.486] <TB1> INFO: running: xray
[09:06:46.486] <TB1> INFO: readGainPedestalParameters /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2162_XrayQualification_2016-02-24_09h58m_1456304322//004_HRData_50//phCalibrationFitErr35_C15.dat
[09:06:46.719] <TB1> INFO: ######################################################################
[09:06:46.719] <TB1> INFO: PixTestXray::doTest()
[09:06:46.719] <TB1> INFO: ######################################################################
[09:06:46.719] <TB1> INFO: ----------------------------------------------------------------------
[09:06:46.719] <TB1> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:06:46.719] <TB1> INFO: ----------------------------------------------------------------------
[09:06:47.446] <TB1> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:06:53.630] <TB1> INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:07:06.747] <TB1> WARNING: Detected DESER400 trailer error bits: "CODE ERROR"
[09:07:06.747] <TB1> WARNING: Detected DESER400 trailer error bits: "CODE ERROR"
[09:07:06.748] <TB1> ERROR: <datapipe.cc/CheckEventID:L469> Channel 2 Event ID mismatch: local ID (86) != TBM ID (87)
[09:07:06.748] <TB1> ERROR: <datapipe.cc/CheckEventID:L469> Channel 3 Event ID mismatch: local ID (86) != TBM ID (87)
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a25a 8000 40e0 e0 286c 40e0 253 284e 75a 2a65 40e0 113 2482 455 264f 505 2848 40e1 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a254 80b0 40f0 40f0 454 2648 4db 2463 40e0 40e1 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a255 80c0 40e0 40e0 159 224d 521 2484 40f0 40e0 853 204f e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a256 8000 40e0 40e0 40e0 40e0 c5 204d 612 206b fff 2fff fff 2fff fff 2fff fff 2fff f400 d400
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a257 8040 40e0 40e0 411 2225 481 244f 40f0 40f0 59 244d e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a258 80b0 40f0 6dc 204f 40e0 40e0 660 2044 6cd 2244 40e0 615 2a6d e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a259 80c0 40e0 40e0 500 244f 553 224f 40e0 512 2245 40e0 c3 226b e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a35a 8000 40e0 853 2048 40e0 54 222f 40e0 40e0 4d5 2a48 659 2483 fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a354 80b0 40f0 40f0 40f0 40e1 fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a355 80c0 40e0 705 2445 40e0 40f0 40f1 fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a356 8000 40e0 9c 2a4c 54a 2645 40e0 40e0 413 282e 600 2649 40e0 821 264f 855 2849 f400 d400
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a357 8040 40e0 40e0 40e0 cc 2041 40f1 fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a358 80b0 40f0 40f0 11d 2849 40e0 843 204f 40e1 fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a359 80c0 40e0 71c 2825 40e0 759 2044 40e0 40e1 fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> WARNING: Channel 2 ROC 0: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 3 ROC 0: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a262 8000 40e0 344 2828 711 2629 40e0 740 2449 40e1 322 282f 40e1 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a25c 80b0 40e0 115 2445 4cd 2841 40e0 74c 282f 40e0 40d 264e 40e1 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a25d 80c0 40e0 44a 2848 841 2a2f 40e0 e1 2a4e 149 2268 21a 204f 443 2660 40f0 3 204a 500 262e 685 2046 40e1 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a25e 8000 40e0 443 264c 40e0 4c3 244f 40e0 48b 2a68 40e1 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a25f 8040 40e2 83 2260 290 262f 2cb 2267 40b 2a40 40e2 40e2 40e2 b 264f 6dc 2843 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a260 80b0 40e1 40e1 41 2a2c 68a 282c 68a 2a43 40e1 71a 2a4f 40e1 61 2681 e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a261 80c0 40e0 40e0 40e0 494 264a 40e1 fff 2fff fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a362 8000 40e0 40e0 40e1 40e1 4a2 286d fff 2fff fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a35c 80b0 40e0 40e0 40e0 61b 2a49 40e1 fff 2fff fff 2fff fff 2fff e000 c000
[09:07:06.748] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a35d 80c0 40e0 559 2640 40e0 40e0 40e1 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[09:07:06.749] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a35e 8000 40e0 40e0 55a 2462 40e0 40e1 fff 2fff fff 2fff e000 c000
[09:07:06.749] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a35f 8040 40e2 40e2 40e2 40e2 81 242f fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[09:07:06.749] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a360 80b0 40e1 40e1 a 2845 40e1 6d8 204f 841 262d 40e1 fff 2fff fff 2fff e000 c000
[09:07:06.749] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a361 80c0 40e1 25d 244c 284 2865 40e1 40e1 113 2042 720 2242 40e1 e000 c000
[09:07:21.742] <TB1> INFO: Resuming triggers.
[09:07:27.932] <TB1> INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:07:56.644] <TB1> INFO: Resuming triggers.
[09:08:02.830] <TB1> INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[09:08:31.719] <TB1> INFO: Resuming triggers.
[09:08:37.907] <TB1> INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[09:09:07.084] <TB1> INFO: Resuming triggers.
[09:09:13.272] <TB1> INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[09:09:41.661] <TB1> INFO: Resuming triggers.
[09:09:47.846] <TB1> INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[09:10:17.015] <TB1> INFO: Resuming triggers.
[09:10:23.202] <TB1> INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:10:51.759] <TB1> INFO: Resuming triggers.
[09:10:57.943] <TB1> INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[09:11:26.615] <TB1> INFO: Resuming triggers.
[09:11:32.801] <TB1> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[09:12:01.670] <TB1> INFO: Resuming triggers.
[09:12:07.852] <TB1> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[09:12:37.050] <TB1> INFO: Resuming triggers.
[09:12:43.228] <TB1> INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[09:13:12.836] <TB1> INFO: Resuming triggers.
[09:13:19.019] <TB1> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:13:48.572] <TB1> INFO: Resuming triggers.
[09:13:54.755] <TB1> INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:14:23.430] <TB1> INFO: Resuming triggers.
[09:14:29.612] <TB1> INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[09:14:58.643] <TB1> INFO: Resuming triggers.
[09:15:04.825] <TB1> INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[09:15:32.494] <TB1> INFO: Resuming triggers.
[09:15:38.672] <TB1> INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[09:16:07.570] <TB1> INFO: Resuming triggers.
[09:16:08.719] <TB1> INFO: data taking finished, elapsed time: 100 seconds.
[09:16:14.082] <TB1> INFO: PixTest:: pg_setup set to default.
[09:16:14.083] <TB1> INFO: PixTestXray::doPhRun() done
[09:16:14.083] <TB1> INFO: PixTestXray::doTest() done
[09:16:14.264] <TB1> INFO: enter test to run
[09:16:14.264] <TB1> INFO: test: no parameter change
[09:16:14.500] <TB1> QUIET: Connection to board 147 closed.
[09:16:14.579] <TB1> INFO: pXar: this is the end, my friend