Bug #315
CA provider changed messages in logfile
0%
Description
hello,
I see a lot of messages (>10 per sec) in the logfile of tvheadend:
[DEBUG]:PSI: Transport "Montage Technology DS3000/TS2020/CANALDIGITAAL: 12,343,500 kHz Horizontal (Default)/DORCEL TV" PMT (version 31) updated, CA provider changed
I configured rsyslog so tvheadend has its own logfile and I have excluded this specific message so it does not flood my logfile.
However, tvheadend crashes very often. Most often when I record 4 or more programs on the same tuner (test setup only has one tuner).
The messages only appear when the tuner is tuned to this mux, so tuning to another mux removes the problem. Will try to reproduce it by recording 4 programs on another mux, but then this are 2 issues I guess.
I had some issues with my network and usb on this specific machine but I have solved them all and it's running rock solid. However the tvheadend process just segfaults whenever I put some load on it. I do suspect the above message to be at least part of the cause, but cannot prove it. Besides that, I do think it's some kind of bug?
I am running tvheadend r5512 on fedora 13, 32bit, latest patches, kernel 2.6.33.6-147.2.4.fc13.i686 with a Tevii S660 with the latest firmware and driver from the vendor.
I am currently running tvheadend in a gdb session. For the meantime I attached the logfile of the latest session (without all the CA provider messages).
grtz
Jouk
Files
History
Updated by Jouk Hettema - about 14 years ago
I did the following tests when running tvheadend in gdb:
- recorded up to 6 concurrent programs during 2,5 hours without any problems on the same mux (single tuner). I haven't seen all recordings yet, but it seems that the quality is good enough (not much lost frames). The transports were SD and 704x576 mpeg2. They are broadcasted on a dvb-s mux.
- recorded up to 3 concurrent programs during 0,5 hours without any problems on the same mux (single tuner). The transports were HD and 1280x786 h264. They are broadcasted on a dvb-s2 mux.
- recorded up to 2 concurrent programs during 0,5 hours on the same mux with s...load of debug messages in the gdb screen about the CA provider changed. The transports were SD and 704x576 mpeg2. They are broadcasted on a dvb-s mux.
- recorded up to 3 - 8 concurrent programs during 0,5 hours on the same mux with s...load of debug messages in the gdb screen about the CA provider changed. The transports were SD and 704x576 mpeg2. They are broadcasted on a dvb-s mux.
Will keep running this in the debugger with a lot of recordings on the same mux (the one that is generating the debug messages).
Updated by Jouk Hettema - about 14 years ago
(gdb) info reg
eax 0x0 0
ecx 0x0 0
edx 0x0 0
ebx 0x823eb28 136571688
esp 0xb5ffd940 0xb5ffd940
ebp 0xb5ffd998 0xb5ffd998
esi 0x1f 31
edi 0x100 256
eip 0x805b232 0x805b232 <parse_sc+418>
eflags 0x10246 [ PF ZF IF RF ]
cs 0x73 115
ss 0x7b 123
ds 0x7b 123
es 0x7b 123
fs 0x0 0
gs 0x33 51
(gdb)
(gdb) disassemble $pc-32,$pc+32
Dump of assembler code from 0x805b212 to 0x805b252:
0x0805b212 <parse_sc+386>: mov $0x0,%dl
0x0805b214 <parse_sc+388>: add %al,(%eax)
0x0805b216 <parse_sc+390>: mov -0x20(%ebp),%eax
0x0805b219 <parse_sc+393>: mov %eax,(%esp)
0x0805b21c <parse_sc+396>: call 0x804bab0 <sbuf_reset>
0x0805b221 <parse_sc+401>: mov 0xac(%ebx),%edx
0x0805b227 <parse_sc+407>: mov %edi,%eax
0x0805b229 <parse_sc+409>: mov 0xa8(%ebx),%ecx
0x0805b22f <parse_sc+415>: shr $0x18,%eax
=> 0x0805b232 <parse_sc+418>: mov %al,(%ecx,%edx,1)
0x0805b235 <parse_sc+421>: mov 0xa8(%ebx),%ecx
0x0805b23b <parse_sc+427>: mov %edi,%eax
0x0805b23d <parse_sc+429>: shr $0x10,%eax
0x0805b240 <parse_sc+432>: mov %al,0x1(%ecx,%edx,1)
0x0805b244 <parse_sc+436>: mov 0xa8(%ebx),%ecx
0x0805b24a <parse_sc+442>: mov %edi,%eax
0x0805b24c <parse_sc+444>: shr $0x8,%eax
0x0805b24f <parse_sc+447>: mov %al,0x2(%ecx,%edx,1)
End of assembler dump.
(gdb) bt full
#0 0x0805b232 in parse_sc (t=0x823e768, st=0x823eb28, data=0x841c934 "", len=184, vp=0x805b4e0 <parse_mpeg2video> at /usr/src/tvheadend/src/parsers.c:345
sc = 256
i = <value optimized out>
r = <value optimized out>
#1 0x0805d4f1 in ts_recv_packet0 (t=0x823e768, st=<value optimized out>, tsb=0x841c930 "GB\a\022") at /usr/src/tvheadend/src/tsdemux.c:123
off = <value optimized out>
pusi = 1
cc = <value optimized out>
error = 0
#2 0x08070920 in cwc_descramble (td=0x864f350, t=0x823e768, st=0x823eb28,
tsb=0xb5ffdd50 "G\002\a\337\355\366\266_\344ay\226\354\246\021\222\370<\242\324\352\203'\351\236[I\036+8=\026\377\070Ve\330\353\264\311u\376\315\005\342/\034N\231\263\252T\351\005\356\322}\177\213\240\376\231\235\262[\376\344\241\030\066Y\204O\356\300Yr\244\213\063/\005\205\200tVN\263\333\027\201\201\321a\006:\346\r\304mI\244/\337PS\024\022\340\340^X{O&(\325g6a\036\375{\356\373\216\313\344\350P߁\305D\206\373\034\063\062\362\034h:\b\001\263\022\366\304脂I\245\227\273\220\306;zM\016\\_{\304\004N,\004\270V\373\355\253\244\035B\020\203r\236u\236:\021\345\205G\002\004\321\374B\245\375\266h\240\217"...)
at /usr/src/tvheadend/src/cwc.c:1376
i = <value optimized out>
t0 = 0x841c930 "GB\a\022"
ct = 0x864f350
r = 140
vec = {0x0, 0x841f3c8 "7\352\"\201\251 ", 0x0}
PRETTY_FUNCTION = "cwc_descramble"
#3 0x0805d9dd in ts_recv_packet1 (t=0x823e768,
tsb=0xb5ffdd50 "G\002\a\337\355\366\266_\344ay\226\354\246\021\222\370<\242\324\352\203'\351\236[I\036+8=\026\377\070Ve\330\353\264\311u\376\315\005\342/\034N\231\263\252T\351\005\356\322}\177\213\240\376\231\235\262[\376\344\241\030\066Y\204O\356\300Yr\244\213\063/\005\205\200tVN\263\333\027\201\201\321a\006:\346\r\304mI\244/\337PS\024\022\340\340^X{O&(\325g6a\036\375{\356\373\216\313\344\350P߁\305D\206\373\034\063\062\362\034h:\b\001\263\022\366\304脂I\245\227\273\220\306;zM\016\\_{\304\004N,\004\270V\373\355\253\244\035B\020\203r\236u\236:\021\345\205G\002\004\321\374B\245\375\266h\240\217"..., pcrp=0x0)
at /usr/src/tvheadend/src/tsdemux.c:240
st = 0x823eb28
n = 1
m = <value optimized out>
r = <value optimized out>
td = 0x864f350
error = 0
#4 0x08080c48 in dvb_adapter_input_dvr (aux=0x81f28b8) at /usr/src/tvheadend/src/dvb/dvb_adapter.c:540
tda = 0x81f28b8
fd = 12
i = <value optimized out>
r = 1880
tsb = "G\002\003۷ù\234:\276\247\rӷ\253#\223\366\205\204E\351ײ7\356?u}\"\244ش\202fg\207\035J0IStң\330\067\200\237\025\336\003\237\3022̓\005\214\254U\257\255\334T\3055ֵ\031\233\211\307\370\350\272(\030\276[\376\031o\257\065\320xF\207\327\021H\242=m)n<J\214\356\203Ag|\270'P\020\361\025,3\262\320\366u\333\303\300P\324:\340當G#\341\344z<\202\061\244\250\226X\200\206\335\031\274\274\213\351uc\347މ\236\325\r:\310\003\355@/\226\352\230\020\024a\004\341)\271\350\035\022\202\035\210\227
\000F\026}\377\a\001\341\367\236G\002\005\234\212?\276S0\t\312W\341\026V\346\362\315>\264v\337|\003\371\032\005\031X\217\236]\313\310\004N\200Zs\301\005v\006Tt\004C$\255\233\263\234\222\222\024\221\360u\317\312\342\233\351ҚY\315\311I\200\300\021\226\371\244\235X'\021\232&h\352\371\035\374\324\031\270\071\251\321\371\206{\017S\241\224\223\232_\017\232.0ɪ\202\267\270\300i\024Y\274U\321\b\267\006(\237 \316w\034\026P0W8\243-\357OI\031\203\300'{=\217\272\352N\024\300\317\303\372\214\aF\257r^<\210\aJcϤn\250j\003\237\207\235<\317½\256\322W\t\266\365\264RG7\227cG\002\a\337\355\366\266_\344ay\226\354\246\021\222\370<\242"...
t = 0x823e768
#5 0x00193919 in start_thread (arg=0xb5ffeb70) at pthread_create.c:301
+res = <value optimized out>
+ignore1 = 0
+ignore2 = 0
pd = 0xb5ffeb70
now = <value optimized out>
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {1724404, 0, 4001536, 1241521064, -110339946, 886787069}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0,
not_first_call = <value optimized out>
pagesize_m1 = <value optimized out>
sp = <value optimized out>
freesize = <value optimized out>
---Type <return> to continue, or q <return> to quit--
#6 0x002afcce in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:133
No locals.
(gdb)
Updated by Jouk Hettema - about 14 years ago
the gdb output above when the tvheadend binary segfaulted. Hopefully this will help in quickly solving this issue, because this is the only thing which prevents production (at home ).
will attach the logfile (without the CA messages) as well.
Updated by Jouk Hettema - about 14 years ago
did the same test last night, and apparently the PSI debug message was gone for a couple of hours. I scheduled some hours of programs on that specific mux and for about 4 hours it ran ok with at least 6 transports recording, sometimes 8 or 9.
This morning the PSI debug message was back again and when I scheduled some recordings it segfaulted again. attached the debug output.
regards
Jouk
Updated by Andreas Smas over 13 years ago
- Status changed from New to Accepted
- Target version changed from 3.0 to 2.13
Updated by Adam Sutton over 12 years ago
- Status changed from Accepted to Rejected
- Found in version set to unknown
Not likely to get any attention on the grounds of age. If its still happening with latest git source, please re-submit.