Debugging » History » Version 26
Mark Clarkstone, 2017-11-11 12:18
1 | 1 | Adam Sutton | h1. Debugging |
---|---|---|---|
2 | |||
3 | 26 | Mark Clarkstone | If you use the packaged version of tvheadend, make sure that you use the debug version of tvheadend (with the debugging symbols). For debian/ubuntu these packages have *-dbg* suffix, for rpm packages, these symbols are in *debuginfo* rpm files. |
4 | 19 | Jaroslav Kysela | |
5 | 1 | Adam Sutton | If you're going to be regularly trying development versions of Tvheadend or need to report a crash or deadlock then you should really read this page! |
6 | |||
7 | 7 | Jaroslav Kysela | If you are investigating problems within Tvheadend then its worth being familiar with tools such as gdb and valgrind or clang, although these are not covered here. |
8 | 1 | Adam Sutton | |
9 | However one thing that can be useful in investigating crashes within Tvheadend is to ensure that coredumps are generated, this will allow post analysis in gdb without having to actual run Tvheadend within gdb. |
||
10 | |||
11 | You can enable temporarily by running: |
||
12 | |||
13 | <pre> |
||
14 | ulimit -c unlimited |
||
15 | </pre> |
||
16 | |||
17 | To make this permanent put this somewhere in your shell environment setup (.bashrc, .profile, etc...) |
||
18 | Firstly I'd recommend that if you're specifically trying to investigate an issue then you should consider running Tvheadend manually, rather than as a service, as documented [[Development|here]]. |
||
19 | |||
20 | h2. Logging |
||
21 | |||
22 | I'd strongly recommend that if you're specifically trying to investigate a crash or other problem in Tvheadend that you enable debugging: |
||
23 | |||
24 | * *-s* will output debug info to syslog |
||
25 | * *--debug* allows you to specify which subsystem to debug (TODO: add more info) |
||
26 | * *--trace* allows you to enable trace (more in-depth) logging on specific subsystems |
||
27 | |||
28 | You can also get Tvheadend to log to it's own file using: |
||
29 | |||
30 | <pre> |
||
31 | -l FILE |
||
32 | </pre> |
||
33 | |||
34 | 2 | Jaroslav Kysela | You may also modify the debug settings using WEB GUI as admin - Configuration/Debugging. Note that the information is not saved, |
35 | it is just set for run-time (current task). |
||
36 | |||
37 | * Debug log path - filename to store log |
||
38 | * Debug trace - enable traces |
||
39 | * Debug subsystems - comma separated list of subsystems |
||
40 | * Trace subsystems - comma separated list of subsystems |
||
41 | |||
42 | 3 | Jaroslav Kysela | The traces must be compiled to the tvheadend binary - see [[Traces]]. |
43 | 2 | Jaroslav Kysela | |
44 | 21 | Jaroslav Kysela | h2. Incorrect (not useable) crash reports |
45 | |||
46 | <pre> |
||
47 | 22 | Jaroslav Kysela | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: Signal: 11 in PRG: /usr/bin/tvheadend (4.3-193~ga4ff519) [15a15a895adaf9c5760b80707f582c2d60cfab01] CWD: / |
48 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: Fault address 0x90 (Address not mapped) |
||
49 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: STACKTRACE |
||
50 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x555558549eba 0x555558350000 |
||
51 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x7f3d97c0c0c0 0x7f3d97bfb000 |
||
52 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x555558525620 0x555558350000 |
||
53 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x5555585257a8 0x555558350000 |
||
54 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585db371 0x555558350000 |
||
55 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585dc1f2 0x555558350000 |
||
56 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585c3212 0x555558350000 |
||
57 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585bb71d 0x555558350000 |
||
58 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585bb8d1 0x555558350000 |
||
59 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x5555585b4589 0x555558350000 |
||
60 | Jun 6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x5555585b4796 0x555558350000 |
||
61 | Jun 6 15:01:09 srv tvheadend[10808]: CRASH: ??:0 0x555558511e44 0x555558350000 |
||
62 | Jun 6 15:01:09 srv tvheadend[10808]: CRASH: ??:0 0x7f3d97c02494 0x7f3d97bfb000 |
||
63 | Jun 6 15:01:09 srv kernel: [2320412.837462] tvh:mi-table[11208]: segfault at 90 ip 0000555558525620 sp 00007f3d85ff0b98 error 4 in tvheadend[555558350000+10d1000] |
||
64 | 21 | Jaroslav Kysela | </pre> |
65 | |||
66 | 25 | Jaroslav Kysela | In this case, the debug symbols are missing (look to the top of this page). Install the debug version of the tvheadend package. |
67 | 21 | Jaroslav Kysela | |
68 | 23 | Jaroslav Kysela | h2. Correct crash reports |
69 | |||
70 | <pre> |
||
71 | 2017-06-06 17:36:53.626 [ ALERT] CRASH: Signal: 6 in PRG: ./build.linux/tvheadend (4.3-195~gf476b37-dirty) [d761557cdfcd10940d79f8758376fadda7e49e8c] CWD: /home/tvheadend/git/tvheadend |
||
72 | 2017-06-06 17:36:53.626 [ ALERT] CRASH: Fault address 0x311100002adf (N/A) |
||
73 | 2017-06-06 17:36:53.626 [ ALERT] CRASH: STACKTRACE |
||
74 | 2017-06-06 17:36:53.626 [ ALERT] CRASH: backtrace+0x41 (./build.linux/tvheadend) |
||
75 | 2017-06-06 17:36:53.643 [ ALERT] CRASH: /home/tvheadend/git/tvheadend/src/trap.c:148 0x5584f45ad4ef 0x5584f3d72000 |
||
76 | 2017-06-06 17:36:53.666 [ ALERT] CRASH: ??:0 0x7f1afde155c0 0x7f1afde04000 |
||
77 | 2017-06-06 17:36:53.666 [ ALERT] CRASH: gsignal+0x9f (/lib64/libc.so.6) |
||
78 | 2017-06-06 17:36:53.666 [ ALERT] CRASH: abort+0x16a (/lib64/libc.so.6) |
||
79 | 2017-06-06 17:36:53.690 [ ALERT] CRASH: /home/tvheadend/git/tvheadend/src/main.c:1267 0x5584f4462996 0x5584f3d72000 |
||
80 | 2017-06-06 17:36:53.690 [ ALERT] CRASH: __libc_start_main+0xf1 (/lib64/libc.so.6) |
||
81 | </pre> |
||
82 | |||
83 | 4 | Jaroslav Kysela | h2. Basic crash debug |
84 | |||
85 | You may run tvh in gdb directly using command: |
||
86 | |||
87 | <pre> |
||
88 | gdb --args /the standard tvh command line/ |
||
89 | 5 | Jaroslav Kysela | |
90 | (gdb) run |
||
91 | 4 | Jaroslav Kysela | </pre> |
92 | |||
93 | Or attach gdb to the running process: |
||
94 | |||
95 | <pre> |
||
96 | gdb tvheadend pid |
||
97 | 5 | Jaroslav Kysela | |
98 | (gdb) continue |
||
99 | 4 | Jaroslav Kysela | </pre> |
100 | |||
101 | 17 | Jaroslav Kysela | The 'continue' command will continue the execution of the program. If you need to _break_ the execution and return to gdb, just use 'Ctrl-C'. |
102 | |||
103 | 4 | Jaroslav Kysela | You may need to replace _tvheadend_ with the full path to the binary and you will need to replace _pid_ with the PID of the running process. To find that run: |
104 | |||
105 | <pre> |
||
106 | ps -C tvheadend |
||
107 | </pre> |
||
108 | |||
109 | Once you have gdb attached grab a stack trace from every thread using the following command: |
||
110 | |||
111 | <pre> |
||
112 | (gdb) set logging on |
||
113 | (gdb) set pagination off |
||
114 | (gdb) bt full |
||
115 | </pre> |
||
116 | |||
117 | Note: "set logging on" will cause GDB to write its output to a file, by default this will be gdb.txt in the current directory. |
||
118 | |||
119 | 1 | Adam Sutton | h2. Enabling coredumps |
120 | |||
121 | 4 | Jaroslav Kysela | If you need to investigate some running problem you can always attach (see below) later and if you need to trap crashes, then you can configure your system to generate a core file and then retrospectively analyse this with gdb. |
122 | 1 | Adam Sutton | |
123 | If you're running manually you should enable coredumps in your environment: |
||
124 | |||
125 | <pre> |
||
126 | ulimit -c unlimited |
||
127 | </pre> |
||
128 | |||
129 | I'd recommend you enable this permanently by putting this command in your shell initialisation scripts (.bashrc etc..). |
||
130 | |||
131 | If you're running as a daemon then you should use the -D command line option, this will enable coredumps from the daemon. If you start using sysvinit, upstart etc... then you will need to put this in the configuration file, e.g.: |
||
132 | |||
133 | <pre> |
||
134 | TVH_ARGS="-D" |
||
135 | </pre> |
||
136 | |||
137 | Finally it's probably worth changing the coredump file format, personally I use the following configuration: |
||
138 | |||
139 | <pre> |
||
140 | echo core.%h.%e.%t | sudo tee /proc/sys/kernel/core_pattern |
||
141 | echo 0 | sudo tee /proc/sys/kernel/core_uses_pid |
||
142 | </pre> |
||
143 | |||
144 | Or put the following in /etc/sysctl.conf: |
||
145 | |||
146 | <pre> |
||
147 | kernel.core_pattern = core.%h.%e.%t |
||
148 | kernel.core_uses_pid = 0 |
||
149 | </pre> |
||
150 | |||
151 | If you're using a system like Ubuntu that uses apport (and cripples the ability to change the core format) just set core_uses_pid=1 instead. |
||
152 | |||
153 | Note: coredumps are (by default) stored in the current working directory, to make it possible for the daemon to write files the current working directory is set to /tmp when using -D, so check there for core files. |
||
154 | |||
155 | To verify that you have everything configured properly you can use the -A option to force a crash on startup. Do this from the command line or add to /etc/default/tvheadend: |
||
156 | |||
157 | <pre> |
||
158 | TVH_ARGS="-D -A" |
||
159 | </pre> |
||
160 | |||
161 | Note: remember to remove the option after you've tested it! |
||
162 | |||
163 | h2. Processing core file. |
||
164 | |||
165 | Once you have a core file you can start up gdb with that coredump, just as if you'd caught the crash while running under gdb: |
||
166 | |||
167 | <pre> |
||
168 | gdb tvheadend core |
||
169 | </pre> |
||
170 | |||
171 | You may need to replace _tvheadend_ and _core_ above with the proper paths. |
||
172 | |||
173 | For most crashes the most useful information is the back trace, this will provide a stack trace showing where the code crashed and the stack information at the time of the crash: |
||
174 | |||
175 | <pre> |
||
176 | (gdb) set logging on |
||
177 | (gdb) set pagination off |
||
178 | (gdb) bt full |
||
179 | #0 0x00007f5b10cc1425 in __GI_raise (sig=<optimised out>) |
||
180 | at ../nptl/sysdeps/unix/sysv/linux/raise.c:64 |
||
181 | resultvar = 0 |
||
182 | pid = <optimised out> |
||
183 | selftid = 7517 |
||
184 | #1 0x00007f5b10cc4b10 in __GI_abort () at abort.c:120 |
||
185 | act = {__sigaction_handler = {sa_handler = 0, sa_sigaction = 0}, |
||
186 | sa_mask = {__val = {18446744073709551615 <repeats 16 times>}}, |
||
187 | sa_flags = 0, sa_restorer = 0} |
||
188 | sigs = {__val = {32, 0 <repeats 15 times>}} |
||
189 | #2 0x000000000040744e in main (argc=<optimised out>, argv=<optimised out>) |
||
190 | at src/main.c:810 |
||
191 | i = <optimised out> |
||
192 | set = {__val = {16386, 0 <repeats 15 times>}} |
||
193 | adapter_mask = <optimised out> |
||
194 | log_level = <optimised out> |
||
195 | log_options = <optimised out> |
||
196 | log_debug = <optimised out> |
||
197 | log_trace = <optimised out> |
||
198 | buf = "/tmp\000\000\000\000\360\350\364\023[\177\000\000\000\320\365\023[\177\000\000t\n\327\023[\177\000\000\370\271\311\020[\177\000\000\017\000\000\000\000\000\000\000:\000\000\000\000\000\000\000h\344\364\023[\177\000\000.N=\366\000\000\000\000\236\022\327\023[\177\000\000\300\304S\205\377\177\000\000.\000\000\000\000\000\000\000 \305S\205\377\177\000\000\377\377\377\377\000\000\000\000\264\352\310\020[\177\000\000\250\354\310\020[\177\000\000\360\304S\205\377\177\000\000\360\350\364\023[\177\000\000@\256\311\020[\177", '\000' <repeats 18 times>"\340, \346\364\023[\177\000\000\000\320\365\023[\177\000\000\231,@\000\000\000\000\000\370\271\311\020[\177\000\000\340\033@\000\000\000\000\000\000\000\000\000\001\000\000\000\021\b\000\000\001", '\000' <repeats 11 times>, " \266\370\023[\177\000\000`\305S\205\377\177\000\000.N=\366\000\000\000\000\340\346\364\023[\177\000\000\200\305S\205\377\177\000\000"... |
||
199 | opt_help = 0 |
||
200 | opt_version = 0 |
||
201 | opt_fork = 1 |
||
202 | opt_firstrun = 0 |
||
203 | opt_stderr = 0 |
||
204 | opt_syslog = 0 |
||
205 | opt_uidebug = 0 |
||
206 | </pre> |
||
207 | |||
208 | Note: "set logging on" will cause GDB to write its output to a file, by default this will be gdb.txt in the current directory. |
||
209 | |||
210 | However I'd strongly recommend that you keep a copy of tvheadend binary and core file in case further analysis is required. |
||
211 | |||
212 | h2. Dead or Live Lock |
||
213 | |||
214 | If Tvheadend appears to die but the process is still running, then its quite possible that the process is deadlocked (or possibly live locked). The best way to help investigate such a problem is to get a full stack trace from every thread in the system. |
||
215 | |||
216 | First attach gdb to the running process: |
||
217 | |||
218 | <pre> |
||
219 | gdb tvheadend pid |
||
220 | 5 | Jaroslav Kysela | |
221 | (gdb) continue |
||
222 | 1 | Adam Sutton | </pre> |
223 | 17 | Jaroslav Kysela | |
224 | 18 | Jaroslav Kysela | The 'continue' command will continue the execution of the program. If you need to _break_ the execution and return to gdb, just use 'Ctrl-C'. |
225 | 1 | Adam Sutton | |
226 | You may need to replace _tvheadend_ with the full path to the binary and you will need to replace _pid_ with the PID of the running process. To find that run: |
||
227 | |||
228 | <pre> |
||
229 | ps -C tvheadend |
||
230 | </pre> |
||
231 | |||
232 | Once you have gdb attached grab a stack trace from every thread using the following command: |
||
233 | |||
234 | <pre> |
||
235 | (gdb) set logging on |
||
236 | (gdb) set pagination off |
||
237 | (gdb) thread apply all bt full |
||
238 | </pre> |
||
239 | |||
240 | Note: "set logging on" will cause GDB to write its output to a file, by default this will be gdb.txt in the current directory. |
||
241 | |||
242 | It might also be useful to generate a core file for good measure: |
||
243 | |||
244 | <pre> |
||
245 | (gdb) generate-core-file |
||
246 | </pre> |
||
247 | |||
248 | This information may give an indication as to why things are locked, often 2 threads are stuck trying to lock a mutex (probably each holds the opposite lock). |
||
249 | |||
250 | h2. Reporting crash (or lock) |
||
251 | |||
252 | 6 | Jaroslav Kysela | If you're going to report a crash (or lockup) then please try to provide the above information, including a debug log (or whatever logging you have), a core file and the tvheadend binary and basic information about the platform (distribution, version and architecture) you're running on. |
253 | 8 | Jaroslav Kysela | |
254 | h1. Memory leaks or corruption |
||
255 | |||
256 | It may be really difficult to track these problems. There are basically two tools which may help to discover the memory leaks or memory corruptions. |
||
257 | |||
258 | h2. Valgrind |
||
259 | |||
260 | It is very slow, but it may be useable for things which are triggered everytime: |
||
261 | |||
262 | <pre> |
||
263 | valgrind --leak-check=full --show-reachable=yes /tvh_command_line/ |
||
264 | </pre> |
||
265 | |||
266 | h2. clang |
||
267 | |||
268 | 24 | Jaroslav Kysela | There is address and leak sanitizer in the clang toolkit. |
269 | 1 | Adam Sutton | |
270 | 24 | Jaroslav Kysela | The clang / llvm tools are usually split to multiple packages, here is list of required packages for Fedora 26: |
271 | |||
272 | 1 | Adam Sutton | <pre> |
273 | 24 | Jaroslav Kysela | llvm |
274 | clang |
||
275 | libasan |
||
276 | liblsan |
||
277 | </pre> |
||
278 | |||
279 | The binary must be rebuild using the clang compiler and libraries: |
||
280 | |||
281 | <pre> |
||
282 | 8 | Jaroslav Kysela | ARGS="/your_configure_arguments/" |
283 | 24 | Jaroslav Kysela | SANITIZER=leak # or address |
284 | 8 | Jaroslav Kysela | export CFLAGS="-fsanitize=$SANITIZER" |
285 | export LDFLAGS="-fsanitize=$SANITIZER" |
||
286 | ./configure $ARGS --disable-pie --enable-ccdebug python=python3 cc=clang ld=clang nowerror |
||
287 | make -j4 |
||
288 | 10 | C K | </pre> |
289 | |||
290 | Example build script (build_with_clang.sh): |
||
291 | |||
292 | <pre> |
||
293 | 1 | Adam Sutton | #!/bin/sh |
294 | 16 | C K | make distclean |
295 | 10 | C K | ARGS="--enable-libffmpeg_static --disable-hdhomerun_static" |
296 | 24 | Jaroslav Kysela | SANITIZER=leak # or address |
297 | 10 | C K | export CFLAGS="-fsanitize=$SANITIZER" |
298 | export LDFLAGS="-fsanitize=$SANITIZER" |
||
299 | 11 | C K | ./configure $ARGS --disable-pie --enable-ccdebug python=python3 cc=clang ld=clang nowerror |
300 | 10 | C K | make -j4 |
301 | </pre> |
||
302 | |||
303 | Make sure to make your script executable. |
||
304 | 12 | Jaroslav Kysela | |
305 | If you do not see resolved the function names like: |
||
306 | |||
307 | <pre> |
||
308 | ==16673==WARNING: Trying to symbolize code, but external symbolizer is not initialized! |
||
309 | #0 0x7fcda9407680 (/home/tvh/src/tvheadend/build.linux/tvheadend+0x65b680) |
||
310 | #1 0x7fcda943b115 (/home/tvh/src/tvheadend/build.linux/tvheadend+0x68f115) |
||
311 | </pre> |
||
312 | |||
313 | 16 | C K | get the correct path for the llvm-symbolizer, i.e. with |
314 | <pre>whereis llvm-symbolizer</pre> |
||
315 | |||
316 | 12 | Jaroslav Kysela | then make sure that you set the external symbolizer like: |
317 | |||
318 | 1 | Adam Sutton | <pre> |
319 | 16 | C K | ASAN_OPTIONS=symbolize=1 ASAN_SYMBOLIZER_PATH=/usr/bin/llvm-symbolizer /home/ts/workspace/tvheadend/build.linux/tvheadend -l thv.log |
320 | 13 | Jaroslav Kysela | </pre> |
321 | |||
322 | The error log should be like: |
||
323 | |||
324 | <pre> |
||
325 | 14 | Jaroslav Kysela | ==27911==ERROR: AddressSanitizer: heap-use-after-free on address 0x60700000d928 at pc 0x56409f916af4 bp 0x7ffc463d6670 sp 0x7ffc463d6668 |
326 | READ of size 8 at 0x60700000d928 thread T0 |
||
327 | 15 | Jaroslav Kysela | #0 0x56409f916af3 in idnode_unlink /home/tvh/git/tvheadend/src/idnode.c:164:94 |
328 | #1 0x56409f9c9f8a in memoryinfo_unregister /home/tvh/git/tvheadend/src/memoryinfo.h:52:3 |
||
329 | #2 0x56409f9c9de2 in streaming_done /home/tvh/git/tvheadend/src/streaming.c:597:3 |
||
330 | 12 | Jaroslav Kysela | </pre> |