Project

General

Profile

Debugging » History » Version 32

Mark Clarkstone, 2018-12-01 17:00

1 32 Mark Clarkstone
{{>toc}}
2
3 1 Adam Sutton
h1. Debugging
4
5 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.
6 19 Jaroslav Kysela
7 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!
8
9 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.
10 1 Adam Sutton
11
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.
12
13
You can enable temporarily by running:
14
15
<pre>
16
ulimit -c unlimited
17
</pre>
18
19
To make this permanent put this somewhere in your shell environment setup (.bashrc, .profile, etc...)
20
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]].
21
22
h2. Logging
23
24
I'd strongly recommend that if you're specifically trying to investigate a crash or other problem in Tvheadend that you enable debugging:
25
26
* *-s* will output debug info to syslog
27
* *--debug* allows you to specify which subsystem to debug (TODO: add more info)
28
* *--trace* allows you to enable trace (more in-depth) logging on specific subsystems
29
30
You can also get Tvheadend to log to it's own file using:
31
32
<pre>
33
-l FILE
34
</pre>
35
36 2 Jaroslav Kysela
You may also modify the debug settings using WEB GUI as admin - Configuration/Debugging. Note that the information is not saved,
37
it is just set for run-time (current task).
38
39
* Debug log path - filename to store log
40
* Debug trace - enable traces
41
* Debug subsystems - comma separated list of subsystems
42
* Trace subsystems - comma separated list of subsystems
43
44 3 Jaroslav Kysela
The traces must be compiled to the tvheadend binary - see [[Traces]].
45 2 Jaroslav Kysela
46 21 Jaroslav Kysela
h2. Incorrect (not useable) crash reports
47
48
<pre>
49 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: /
50
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: Fault address 0x90 (Address not mapped)
51
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: STACKTRACE
52
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x555558549eba 0x555558350000
53
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x7f3d97c0c0c0 0x7f3d97bfb000
54
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x555558525620 0x555558350000
55
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x5555585257a8 0x555558350000
56
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585db371 0x555558350000
57
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585dc1f2 0x555558350000
58
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585c3212 0x555558350000
59
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585bb71d 0x555558350000
60
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:? 0x5555585bb8d1 0x555558350000
61
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x5555585b4589 0x555558350000
62
Jun  6 15:01:08 srv tvheadend[10808]: CRASH: ??:0 0x5555585b4796 0x555558350000
63
Jun  6 15:01:09 srv tvheadend[10808]: CRASH: ??:0 0x555558511e44 0x555558350000
64
Jun  6 15:01:09 srv tvheadend[10808]: CRASH: ??:0 0x7f3d97c02494 0x7f3d97bfb000
65
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]
66 21 Jaroslav Kysela
</pre>
67
68 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.
69 21 Jaroslav Kysela
70 23 Jaroslav Kysela
h2. Correct crash reports
71
72
<pre>
73
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  
74
2017-06-06 17:36:53.626 [  ALERT] CRASH: Fault address 0x311100002adf (N/A)
75
2017-06-06 17:36:53.626 [  ALERT] CRASH: STACKTRACE
76
2017-06-06 17:36:53.626 [  ALERT] CRASH: backtrace+0x41  (./build.linux/tvheadend)
77
2017-06-06 17:36:53.643 [  ALERT] CRASH: /home/tvheadend/git/tvheadend/src/trap.c:148 0x5584f45ad4ef 0x5584f3d72000
78
2017-06-06 17:36:53.666 [  ALERT] CRASH: ??:0 0x7f1afde155c0 0x7f1afde04000
79
2017-06-06 17:36:53.666 [  ALERT] CRASH: gsignal+0x9f  (/lib64/libc.so.6)
80
2017-06-06 17:36:53.666 [  ALERT] CRASH: abort+0x16a  (/lib64/libc.so.6)
81
2017-06-06 17:36:53.690 [  ALERT] CRASH: /home/tvheadend/git/tvheadend/src/main.c:1267 0x5584f4462996 0x5584f3d72000
82
2017-06-06 17:36:53.690 [  ALERT] CRASH: __libc_start_main+0xf1  (/lib64/libc.so.6)
83
</pre>
84
85 4 Jaroslav Kysela
h2. Basic crash debug
86
87
You may run tvh in gdb directly using command:
88
89
<pre>
90
gdb --args /the standard tvh command line/
91 5 Jaroslav Kysela
92
(gdb) run
93 4 Jaroslav Kysela
</pre>
94
95
Or attach gdb to the running process:
96
97
<pre>
98
gdb tvheadend pid
99 5 Jaroslav Kysela
100
(gdb) continue
101 4 Jaroslav Kysela
</pre>
102
103 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'.
104
105 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:
106
107
<pre>
108
ps -C tvheadend
109
</pre>
110
111
Once you have gdb attached grab a stack trace from every thread using the following command:
112
113
<pre>
114
(gdb) set logging on
115
(gdb) set pagination off
116
(gdb) bt full
117
</pre>
118
119
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.
120
121 1 Adam Sutton
h2. Enabling coredumps
122
123 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.
124 1 Adam Sutton
125
If you're running manually you should enable coredumps in your environment:
126
127
<pre>
128
ulimit -c unlimited
129
</pre>
130
131
I'd recommend you enable this permanently by putting this command in your shell initialisation scripts (.bashrc etc..).
132
133
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.:
134
135
<pre>
136
TVH_ARGS="-D"
137
</pre>
138
139
Finally it's probably worth changing the coredump file format, personally I use the following configuration:
140
141
<pre>
142
echo core.%h.%e.%t | sudo tee /proc/sys/kernel/core_pattern
143
echo 0 | sudo tee /proc/sys/kernel/core_uses_pid
144
</pre>
145
146
Or put the following in /etc/sysctl.conf:
147
148
<pre>
149
kernel.core_pattern = core.%h.%e.%t
150
kernel.core_uses_pid = 0
151
</pre>
152
153
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.
154
155
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.
156
157
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:
158
159
<pre>
160
TVH_ARGS="-D -A"
161
</pre>
162
163
Note: remember to remove the option after you've tested it!
164
165
h2. Processing core file.
166
167
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:
168
169
<pre>
170
gdb tvheadend core
171
</pre>
172
173
You may need to replace _tvheadend_ and _core_ above with the proper paths.
174
175
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:
176
177
<pre>
178
(gdb) set logging on
179
(gdb) set pagination off
180
(gdb) bt full
181
#0  0x00007f5b10cc1425 in __GI_raise (sig=<optimised out>)
182
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
183
        resultvar = 0
184
        pid = <optimised out>
185
        selftid = 7517
186
#1  0x00007f5b10cc4b10 in __GI_abort () at abort.c:120
187
        act = {__sigaction_handler = {sa_handler = 0, sa_sigaction = 0}, 
188
          sa_mask = {__val = {18446744073709551615 <repeats 16 times>}}, 
189
          sa_flags = 0, sa_restorer = 0}
190
        sigs = {__val = {32, 0 <repeats 15 times>}}
191
#2  0x000000000040744e in main (argc=<optimised out>, argv=<optimised out>)
192
    at src/main.c:810
193
        i = <optimised out>
194
        set = {__val = {16386, 0 <repeats 15 times>}}
195
        adapter_mask = <optimised out>
196
        log_level = <optimised out>
197
        log_options = <optimised out>
198
        log_debug = <optimised out>
199
        log_trace = <optimised out>
200
        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"...
201
        opt_help = 0
202
        opt_version = 0
203
        opt_fork = 1
204
        opt_firstrun = 0
205
        opt_stderr = 0
206
        opt_syslog = 0
207
        opt_uidebug = 0
208
</pre>
209
210
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.
211
212
However I'd strongly recommend that you keep a copy of tvheadend binary and core file in case further analysis is required.
213
214
h2. Dead or Live Lock
215
216 28 Jaroslav Kysela
If Tvheadend appears to die but the process is still running, then its quite possible that the process is deadlocked (or possibly live locked).
217
218
h3. Buildin deadlock mutex checker (since latest 4.3 version)
219
220
Use '--thrdebug 1' as the command line option. The deadlock will be printed to the tvheadend's configuration directory to file *mutex-deadlock.txt* and to the standard task error output (so you can see it through the systemctl service log for example).
221
222
h3. GDB
223
224
The best way to help investigate such a problem is to get a full stack trace from every thread in the system.
225 1 Adam Sutton
226
First attach gdb to the running process:
227
228
<pre>
229
gdb tvheadend pid
230 5 Jaroslav Kysela
231
(gdb) continue
232 1 Adam Sutton
</pre>
233 17 Jaroslav Kysela
234 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'.
235 1 Adam Sutton
236
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:
237
238
<pre>
239
ps -C tvheadend
240
</pre>
241
242
Once you have gdb attached grab a stack trace from every thread using the following command:
243
244
<pre>
245
(gdb) set logging on
246
(gdb) set pagination off
247
(gdb) thread apply all bt full
248
</pre>
249
250
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.
251
252
It might also be useful to generate a core file for good measure:
253
254
<pre>
255
(gdb) generate-core-file
256
</pre>
257
258
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).
259
260
h2. Reporting crash (or lock)
261
262 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.
263 8 Jaroslav Kysela
264
h1. Memory leaks or corruption
265
266
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.
267
268
h2. Valgrind
269
270
It is very slow, but it may be useable for things which are triggered everytime:
271
272
<pre>
273 27 Jaroslav Kysela
valgrind --suppressions=support/valgrind.supp --leak-check=full --show-reachable=yes /tvh_command_line/
274 8 Jaroslav Kysela
</pre>
275
276
h2. clang
277
278 24 Jaroslav Kysela
There is address and leak sanitizer in the clang toolkit.
279 1 Adam Sutton
280 24 Jaroslav Kysela
The clang / llvm tools are usually split to multiple packages, here is list of required packages for Fedora 26:
281
282 1 Adam Sutton
<pre>
283 24 Jaroslav Kysela
llvm
284
clang
285
libasan
286
liblsan
287
</pre>
288
289
The binary must be rebuild using the clang compiler and libraries:
290
291
<pre>
292 8 Jaroslav Kysela
ARGS="/your_configure_arguments/"
293 24 Jaroslav Kysela
SANITIZER=leak # or address
294 8 Jaroslav Kysela
export CFLAGS="-fsanitize=$SANITIZER"
295
export LDFLAGS="-fsanitize=$SANITIZER"
296
./configure $ARGS --disable-pie --enable-ccdebug python=python3 cc=clang ld=clang nowerror
297
make -j4
298 10 C K
</pre>
299
300
Example build script (build_with_clang.sh):
301
302
<pre>
303 1 Adam Sutton
#!/bin/sh
304 16 C K
make distclean
305 10 C K
ARGS="--enable-libffmpeg_static --disable-hdhomerun_static"
306 24 Jaroslav Kysela
SANITIZER=leak # or address
307 10 C K
export CFLAGS="-fsanitize=$SANITIZER"
308
export LDFLAGS="-fsanitize=$SANITIZER"
309 11 C K
./configure $ARGS --disable-pie --enable-ccdebug python=python3 cc=clang ld=clang nowerror
310 10 C K
make -j4
311
</pre>
312
313
Make sure to make your script executable.
314 12 Jaroslav Kysela
315
If you do not see resolved the function names like:
316
317
<pre>
318
==16673==WARNING: Trying to symbolize code, but external symbolizer is not initialized!
319
    #0 0x7fcda9407680 (/home/tvh/src/tvheadend/build.linux/tvheadend+0x65b680)
320
    #1 0x7fcda943b115 (/home/tvh/src/tvheadend/build.linux/tvheadend+0x68f115)
321
</pre>
322
323 16 C K
get the correct path for the llvm-symbolizer, i.e. with 
324
<pre>whereis llvm-symbolizer</pre>
325
326 12 Jaroslav Kysela
then make sure that you set the external symbolizer like:
327
328 1 Adam Sutton
<pre>
329 16 C K
ASAN_OPTIONS=symbolize=1 ASAN_SYMBOLIZER_PATH=/usr/bin/llvm-symbolizer /home/ts/workspace/tvheadend/build.linux/tvheadend -l thv.log
330 13 Jaroslav Kysela
</pre>
331
332
The error log should be like:
333
334
<pre>
335 14 Jaroslav Kysela
==27911==ERROR: AddressSanitizer: heap-use-after-free on address 0x60700000d928 at pc 0x56409f916af4 bp 0x7ffc463d6670 sp 0x7ffc463d6668
336
READ of size 8 at 0x60700000d928 thread T0
337 15 Jaroslav Kysela
    #0 0x56409f916af3 in idnode_unlink /home/tvh/git/tvheadend/src/idnode.c:164:94
338
    #1 0x56409f9c9f8a in memoryinfo_unregister /home/tvh/git/tvheadend/src/memoryinfo.h:52:3
339
    #2 0x56409f9c9de2 in streaming_done /home/tvh/git/tvheadend/src/streaming.c:597:3
340 12 Jaroslav Kysela
</pre>
341 29 Jaroslav Kysela
342
h1. Mutex profiling
343
344 31 Jaroslav Kysela
The code blocks are protected using mutexes. Tvheadend has the debug interface to show locks which took too much time now (latest 4.3 code). Use '--thrdebug 10020' where 20 means 20 millisecond threshold to show the problematic mutexes. The output is printed to standard error file descriptor (stderr) by default. If you run tvheadend using systemctl or initd, you may send those messages to a UDP port. Set the  TVHEADEND_RTLOG_UDP_PORT environment variable like:
345 29 Jaroslav Kysela
346
<pre>
347
... console 1
348
$ export TVHEADEND_RTLOG_UDP_PORT=7777
349
$ ./build.linux/tvheadend --thrdebug 10020 <more-options>
350
... console 2
351
$ nc -lu -p 7777
352
</pre>
353 30 Jaroslav Kysela
354
The result should look like:
355
356
<pre>
357
thread: mutex 0x5562f9f859e0 at src/api/api_idnode.c:134 took 43ms
358
thread: mutex 0x5562f9f859e0 at src/api/api_idnode.c:134 took 31ms
359
</pre>