[11:50:07.295] <TB2> INFO: *** Welcome to pxar ***
[11:50:07.295] <TB2> INFO: *** Today: 2016/09/29
[11:50:07.362] <TB2> INFO: *** Version: f5d3-dirty
[11:50:07.362] <TB2> INFO: readRocDacs: /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//dacParameters35_C15.dat
[11:50:07.363] <TB2> INFO: readTbmDacs: /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//tbmParameters_C0b.dat
[11:50:07.363] <TB2> INFO: readMaskFile: /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//defaultMaskFile.dat
[11:50:07.363] <TB2> INFO: readTrimFile: /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//trimParameters35_C15.dat
[11:50:07.436] <TB2> INFO: clk: 4
[11:50:07.436] <TB2> INFO: ctr: 4
[11:50:07.436] <TB2> INFO: sda: 19
[11:50:07.436] <TB2> INFO: tin: 9
[11:50:07.436] <TB2> INFO: level: 15
[11:50:07.436] <TB2> INFO: triggerdelay: 0
[11:50:07.436] <TB2> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[11:50:07.436] <TB2> INFO: Log level: INFO
[11:50:07.450] <TB2> INFO: Found DTB DTB_WXENWR
[11:50:07.461] <TB2> QUIET: Connection to board DTB_WXENWR opened.
[11:50:07.463] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 162
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXENWR
MAC address: 40D8551180A2
Hostname: pixelDTB162
Comment:
------------------------------------------------------
[11:50:07.464] <TB2> INFO: RPC call hashes of host and DTB match: 486171790
[11:50:08.999] <TB2> INFO: DUT info:
[11:50:08.999] <TB2> INFO: The DUT currently contains the following objects:
[11:50:08.999] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[11:50:08.999] <TB2> INFO: TBM Core alpha (0): 7 registers set
[11:50:08.999] <TB2> INFO: TBM Core beta (1): 7 registers set
[11:50:08.999] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:50:08.999] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:08.999] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:50:09.400] <TB2> INFO: enter 'restricted' command line mode
[11:50:09.400] <TB2> INFO: enter test to run
[11:50:09.400] <TB2> INFO: test: delay setting parameters: ->5<-
[11:50:09.400] <TB2> INFO: delay test by 5 seconds...
[11:50:14.400] <TB2> INFO: enter test to run
[11:50:14.400] <TB2> INFO: test: Xray no parameter change
[11:50:14.400] <TB2> INFO: running: xray
[11:50:14.400] <TB2> INFO: readGainPedestalParameters /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2336_XrayQualification_2016-09-29_13h35m_1475148923//005_HRData_150//phCalibrationFitErr35_C15.dat
[11:50:14.538] <TB2> INFO: ######################################################################
[11:50:14.538] <TB2> INFO: PixTestXray::doTest()
[11:50:14.538] <TB2> INFO: ######################################################################
[11:50:14.538] <TB2> INFO: ----------------------------------------------------------------------
[11:50:14.538] <TB2> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:50:14.538] <TB2> INFO: ----------------------------------------------------------------------
[11:50:15.261] <TB2> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:50:19.233] <TB2> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[11:50:43.848] <TB2> INFO: Resuming triggers.
[11:50:47.838] <TB2> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[11:51:12.940] <TB2> INFO: Resuming triggers.
[11:51:16.927] <TB2> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:51:41.950] <TB2> INFO: Resuming triggers.
[11:51:45.935] <TB2> INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[11:52:09.710] <TB2> INFO: Resuming triggers.
[11:52:13.693] <TB2> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:52:37.723] <TB2> INFO: Resuming triggers.
[11:52:41.704] <TB2> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:53:06.635] <TB2> INFO: Resuming triggers.
[11:53:10.619] <TB2> INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[11:53:13.788] <TB2> WARNING: Channel 1 ROC 1: Readback start marker after 32 readouts!
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1d2 8000 4810 60b 2282 4810 118 2449 4e2 24c4 60c 2243 4811 ca 266f 24b 2a66 310 246d 65a 2060 4811 1c 244f 12 2a4f 1d 2a82 209 284a 705 224f e000 c000
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1cc 80b0 4810 89 284f 85a 2460 84c 2a2c 4810 281 2868 301 2a6c 692 284e 4810 19 284e 4c 2a82 2d5 286f 619 224f 6a0 2648 843 2080 4810 245 204f 74c 2047 e000 c000
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1cd 80c0 4810 82 2a4e 105 2262 24b 2882 558 2042 6a0 2486 814 2862 801 2a86 4810 95 226c 29a 206a 489 266a 752 264e 4810 98 284e 114 2460 21a 244f 560 2448 812 2664 4811 e000 c000
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1ce 8000 4810 92 224e d2 2060 713 206b 71a 2a4b 4830 2c0 2a6f 4810 4810 d0 2065 851 2222 851 264f e000 c000
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1cf 8040 4812 2 2060 60c 2a49 4812 155 2661 409 2462 4832 650 244f 4812 119 286a 104 264f 518 2665 760 2863 e000 c000
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1d0 80b0 4810 51 244f 4c 2463 248 2667 343 2644 4810 45 2061 5b 2a8a 288 264c 2cd 2461 4810 b 2047 e1 28a6 2c3 2081 852 2449 4811 e000 c000
[11:53:13.788] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a1d1 80c0 4811 112 2666 44a 2082 4811 161 244e 4c4 204e 714 2a4f 4811 448 2a42 498 204b 498 2262 603 2869 4811 88 2468 209 224f 282 246a 51c 284a 742 224e 80c 2669 e000 c000
[11:53:23.501] <TB2> WARNING: Channel 1 ROC 1: Readback start marker after 32 readouts!
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a122 8000 4810 51d 208b 4810 313 26a1 803 282f 85d 284b 4811 291 2883 74b 224a 4811 e000 c000
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a11c 80b0 4810 4810 41 2666 121 2462 100 2a4f 283 2842 4810 30b 2868 30d 2268 85c 246f 4811 e000 c000
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a11d 80c0 4810 4d0 206a 6cc 224a 4810 1 224f 55 2462 220 266a 81c 282c 4810 203 2648 743 204a 4810 113 2846 14c 204c 40c 2a63 e000 c000
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a11e 8000 4810 13 286f 4810 2 2863 849 224a 4810 52 2865 4810 11d 2668 542 2062 6c4 244f e000 c000
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a11f 8040 4812 54 2282 40d 2644 4812 44b 2848 752 244f 4812 714 2840 4812 118 2840 11c 2a4b 29b 2a6f 2c5 206e 560 2441 e000 c000
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a120 80b0 4810 20d 2869 2ca 2a60 705 206c 4810 249 2868 319 2a82 4810 a 262d 148 2a40 349 2269 4810 455 2045 448 264f 448 2a4d 6c2 288e 6c0 2447 e000 c000
[11:53:23.501] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a121 80c0 4811 404 2a44 409 2662 4c3 20a4 4811 4c 224a 58 2a4e 80 2465 89 2666 2d2 2486 41c 284f 649 2a2a 681 2643 4811 553 226e 713 2867 713 2a65 4811 22 2868 15 2069 21b 2862 480 286f 61a 2680 684 2440 80c 244d 809 2247 e000 c000
[11:53:35.150] <TB2> INFO: Resuming triggers.
[11:53:39.131] <TB2> INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[11:54:05.770] <TB2> INFO: Resuming triggers.
[11:54:09.749] <TB2> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:54:34.570] <TB2> INFO: Resuming triggers.
[11:54:38.551] <TB2> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:55:05.335] <TB2> INFO: Resuming triggers.
[11:55:09.311] <TB2> INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:55:34.860] <TB2> INFO: Resuming triggers.
[11:55:38.839] <TB2> INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:56:03.718] <TB2> INFO: Resuming triggers.
[11:56:07.696] <TB2> INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[11:56:32.506] <TB2> INFO: Resuming triggers.
[11:56:36.484] <TB2> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[11:57:01.248] <TB2> INFO: Resuming triggers.
[11:57:05.224] <TB2> INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:57:32.670] <TB2> INFO: Resuming triggers.
[11:57:36.647] <TB2> INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[11:58:02.403] <TB2> INFO: Resuming triggers.
[11:58:06.379] <TB2> INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[11:58:18.584] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 2 Number of ROCs (5) != Token Chain Length (4)
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e9 80c1 4830 a 284e 8 284d 1 2460 162 2487 150 266d 2cb 264c 85a 2a4a 4830 502 2088 6d2 204f 4830 1c 2068 61c 2a6f 4830 8b 2a63 e000 c000
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e3 8041 4830 4831 5 244a 12 2a2f d3 2663 814 204a 811 2468 820 2a8e 84d 264f 860 2a4e 4830 55 206a 4831 20 2a4f 15b 264f e000 c000
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e4 80b1 4830 6d4 226a 4830 2cb 2262 694 2266 4830 4830 6da 284f e000 c000
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e5 80c1 4030 100 246f 101 2268 65a 2061 4830 1c 244e 112 2868 100 2a68 342 246b 6db 2482 753 2282 4830 281 2a45 500 2a65 655 2284 4830 522 2881 e000 c000
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e6 8001 4830 102 204f 822 2a62 4830 414 2263 4dd 246d 4830 122 2a65 2c5 2084 613 284f 4831 ef8 24aa 868 2506 808 2592 898 2596 4830 41 2864 4a0 244e 4a0 2068 481 2069 e000 c000
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e7 8041 4830 9 2866 a1 286f 21d 2445 48c 2082 4830 25d 2a68 85d 244d 84b 2282 4830 4c 2a8f 505 2a82 6c2 2262 720 2a45 760 2865 4830 4c 2a49 11c 2669 301 2a68 49a 266f e000 c000
[11:58:18.584] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e8 80b1 4830 9b 2068 8b 248c 291 2486 412 2064 542 2262 4830 20a 284f 818 2669 81a 2262 849 2280 4830 b 246c 351 2485 444 286e 4830 18 2048 15 284f 605 2669 741 2283 e000 c000
[11:58:32.343] <TB2> INFO: Resuming triggers.
[11:58:36.320] <TB2> INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[11:59:00.871] <TB2> INFO: Resuming triggers.
[11:59:04.843] <TB2> INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:59:30.740] <TB2> INFO: Resuming triggers.
[11:59:34.715] <TB2> INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:59:59.768] <TB2> INFO: Resuming triggers.
[12:00:03.740] <TB2> INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:00:30.056] <TB2> INFO: Resuming triggers.
[12:00:34.027] <TB2> INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:00:58.940] <TB2> INFO: Resuming triggers.
[12:01:02.911] <TB2> INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:01:27.291] <TB2> INFO: Resuming triggers.
[12:01:31.262] <TB2> INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:01:57.477] <TB2> INFO: Resuming triggers.
[12:02:01.447] <TB2> INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:02:25.368] <TB2> INFO: Resuming triggers.
[12:02:26.035] <TB2> INFO: data taking finished, elapsed time: 100 seconds.
[12:02:30.152] <TB2> INFO: PixTest:: pg_setup set to default.
[12:02:30.153] <TB2> INFO: PixTestXray::doPhRun() done
[12:02:30.153] <TB2> INFO: PixTestXray::doTest() done
[12:02:30.331] <TB2> INFO: enter test to run
[12:02:30.331] <TB2> INFO: test: no parameter change
[12:02:30.590] <TB2> QUIET: Connection to board 162 closed.
[12:02:30.670] <TB2> INFO: pXar: this is the end, my friend