Bug #3346
"OSCam new pc-nodmx" doesn't work for me
0%
Description
During my tests I had always problems in using the oscam connection mode "OSCam new pc-nodmx" but I didn't report because I was not able to reproduce it in a reliable way.
I'm using latest tvheadend build (4.1-1070~g3346bcb) and latest oscam build (r11176) with fixes coming from perex.
The following experiment works well using mode 'OSCam pc-nodmx (rev >= 9756)' but fails on second attempt using mode 'OSCam new pc-nodmx (rev >= 10389)'.
oscam config:
[dvbapi] enabled = 1 au = 1 pmt_mode = 4 read_sdt = 1 boxtype = pc-nodmx
experiment script (tuning for 30s each on 5 channels decoded using Nagra TivuSat card):
date ; curl -m 30 http://sauron:9981/play/stream/channel/ca1790e7031906126e4247d7ec4b31b8?title=1%20%3A%20Rai%201%20HD > /dev/null date ; curl -m 30 http://sauron:9981/play/stream/channel/c30c6729734dc07f180a39f9cf88a6b1?title=2%20%3A%20Rai%202%20HD > /dev/null date ; curl -m 30 http://sauron:9981/play/stream/channel/98bd6cd41a9a27d12c8455df60334e42?title=3%20%3A%20Rai%203%20HD > /dev/null date ; curl -m 30 http://sauron:9981/play/stream/channel/0c2cf72af579ef5416e199fdb6429fa2?title=4%20%3A%20Rete%204 > /dev/null date ; curl -m 30 http://sauron:9981/play/stream/channel/b0d90de1c72f30c1ec5f62dd41bfad16?title=5%20%3A%20Canale%205 > /dev/null
The linked logs come from syslog with debug mode enabled from web-interface (but I'm not sure it effectively works); I can provide further trace log on specific modules if requested.
FIRST SCENARIO (success):
tvheadend CA config:
{
"mode": 4,
"camdfilename": "/tmp/camd.socket",
"port": 0,
"class": "caclient_capmt",
"index": 1,
"enabled": true,
"name": "oscam"
}
Script output:
Thu Nov 26 11:42:41 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 25.1M 0 25.1M 0 0 867k 0 --:--:-- 0:00:29 --:--:-- 701kcurl: (28) Operation timed out after 30000 milliseconds with 26720701 bytes received
Thu Nov 26 11:43:11 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 26.7M 0 26.7M 0 0 939k 0 --:--:-- 0:00:29 --:--:-- 1090kcurl: (28) Operation timed out after 30000 milliseconds with 29443597 bytes received
Thu Nov 26 11:43:41 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 22.6M 0 22.6M 0 0 788k 0 --:--:-- 0:00:29 --:--:-- 725kcurl: (28) Operation timed out after 30000 milliseconds with 24661621 bytes received
Thu Nov 26 11:44:11 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 11.2M 0 11.2M 0 0 383k 0 --:--:-- 0:00:29 --:--:-- 264kcurl: (28) Operation timed out after 30000 milliseconds with 11988367 bytes received
Thu Nov 26 11:44:41 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 11.5M 0 11.5M 0 0 395k 0 --:--:-- 0:00:29 --:--:-- 439kcurl: (28) Operation timed out after 30000 milliseconds with 12404274 bytes received
syslog extract: http://slexy.org/view/s21YlXozVr
Multiple runs work without any problem.
SECOND SCENARIO (failure on second run):
switched tvheadend CA config as:
{
"mode": 6,
"camdfilename": "/tmp/camd.socket",
"port": 0,
"class": "caclient_capmt",
"index": 1,
"enabled": true,
"name": "oscam"
}
Restarted oscam and tvheadend to have a clean state for both.
Script output on first run (success... :-| ):
Thu Nov 26 13:12:33 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 33.9M 0 33.9M 0 0 1204k 0 --:--:-- 0:00:28 --:--:-- 1211kcurl: (28) Operation timed out after 30001 milliseconds with 37392293 bytes received
Thu Nov 26 13:13:03 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 31.2M 0 31.2M 0 0 1107k 0 --:--:-- 0:00:28 --:--:-- 1089kcurl: (28) Operation timed out after 30000 milliseconds with 34277948 bytes received
Thu Nov 26 13:13:33 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 21.2M 0 21.2M 0 0 747k 0 --:--:-- 0:00:29 --:--:-- 943kcurl: (28) Operation timed out after 30000 milliseconds with 23619001 bytes received
Thu Nov 26 13:14:03 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 9269k 0 9269k 0 0 317k 0 --:--:-- 0:00:29 --:--:-- 406kcurl: (28) Operation timed out after 30001 milliseconds with 9859127 bytes received
Thu Nov 26 13:14:33 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 11.6M 0 11.6M 0 0 407k 0 --:--:-- 0:00:29 --:--:-- 402kcurl: (28) Operation timed out after 30000 milliseconds with 12554558 bytes received
syslog extract: http://slexy.org/view/s20P52h8rN
Script output on successive runs (failure):
Thu Nov 26 13:15:57 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 13:16:18 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 13:16:39 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 13:17:00 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0curl: (28) Operation timed out after 30001 milliseconds with 0 bytes received
Thu Nov 26 13:17:30 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0curl: (28) Operation timed out after 30001 milliseconds with 0 bytes received
syslog extract: http://slexy.org/view/s2sHtrOGRo
I can stream again switching tvheadend on mode 4 and restarting it (it is not necessary to restart oscam).
Files
History
Updated by Jaroslav Kysela almost 9 years ago
Updated by It's probably oscam's fault. If you enable debug 128 in oscam, you should see lines like:
14:26:19 491A0839 c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0000 14:26:19 491A0839 c (dvbapi) Sending packet to dvbapi client (fd=10): 14:26:19 491A0839 c (dvbapi) 40 3C 6F 2B 00 00 00 00 00 00 00 00 00 00 00 00
If you see sequence "00 40 3C 6F 2B" (first zero byte), then oscam has wrongly set the client protocol in internal variables. I seen this once after my changes, so it's not completely fixed.
Updated by Jaroslav Kysela almost 9 years ago
Trying to reproduce here, but without success yet...
Updated by Jaroslav Kysela almost 9 years ago
- File oscam-migrate-ubuf.patch oscam-migrate-ubuf.patch added
Try v4.1-1071-gf67c102 . And attached patch for oscam.
Updated by Mario D almost 9 years ago
Updated by tvheadend build v4.1-1071-gf67c102 and oscam r11176 patched with your oscam-migrate-ubuf.patch
Second scenario with mode 6:
first run (success):
Thu Nov 26 15:14:39 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 30.7M 0 30.7M 0 0 1072k 0 --:--:-- 0:00:29 --:--:-- 1256kcurl: (28) Operation timed out after 30000 milliseconds with 33410396 bytes received
Thu Nov 26 15:15:09 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 18.2M 0 18.2M 0 0 627k 0 --:--:-- 0:00:29 --:--:-- 740kcurl: (28) Operation timed out after 30000 milliseconds with 19643994 bytes received
Thu Nov 26 15:15:39 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 30.2M 0 30.2M 0 0 1043k 0 --:--:-- 0:00:29 --:--:-- 994kcurl: (28) Operation timed out after 30000 milliseconds with 32346770 bytes received
Thu Nov 26 15:16:09 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 13.6M 0 13.6M 0 0 468k 0 --:--:-- 0:00:29 --:--:-- 551kcurl: (28) Operation timed out after 30000 milliseconds with 14890961 bytes received
Thu Nov 26 15:16:39 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 12.1M 0 12.1M 0 0 436k 0 --:--:-- 0:00:28 --:--:-- 511kcurl: (28) Operation timed out after 30000 milliseconds with 13531650 bytes received
syslog extract (oscam debug 128): http://slexy.org/view/s2JNvM4wfl
Second run (failure):
./test.sh ⏎
Thu Nov 26 15:17:15 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 15:17:36 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 15:17:57 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 15:18:18 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0curl: (28) Operation timed out after 30001 milliseconds with 0 bytes received
Thu Nov 26 15:18:48 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0curl: (28) Operation timed out after 30001 milliseconds with 0 bytes received
syslog extract: http://slexy.org/view/s21aXoabRS
I've just noted that oscam didn't output even a line during the failing experiment!
Updated by Mario D almost 9 years ago
Jaroslav, I don't know what to say: this is what happens on my system.
The outputs of the second scenario enabling the debug of tvheadend on syslog (using the command-line option - see my other recent bug report):
First run:
Thu Nov 26 15:53:43 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 34.4M 0 34.4M 0 0 1180k 0 --:--:-- 0:00:29 --:--:-- 1256kcurl: (28) Operation timed out after 30000 milliseconds with 37041584 bytes received
Thu Nov 26 15:54:13 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 29.0M 0 29.0M 0 0 998k 0 --:--:-- 0:00:29 --:--:-- 1013kcurl: (28) Operation timed out after 30000 milliseconds with 30942981 bytes received
Thu Nov 26 15:54:43 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 25.3M 0 25.3M 0 0 879k 0 --:--:-- 0:00:29 --:--:-- 845kcurl: (28) Operation timed out after 30000 milliseconds with 27147887 bytes received
Thu Nov 26 15:55:13 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 10.5M 0 10.5M 0 0 361k 0 --:--:-- 0:00:29 --:--:-- 455kcurl: (28) Operation timed out after 30000 milliseconds with 11295868 bytes received
Thu Nov 26 15:55:43 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 15.3M 0 15.3M 0 0 525k 0 --:--:-- 0:00:29 --:--:-- 767kcurl: (28) Operation timed out after 30000 milliseconds with 16130028 bytes received
syslog extract (with tvheadend debug): http://slexy.org/view/s2bl4xPMDz
Second run (failure):
Thu Nov 26 15:57:48 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 15:58:09 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:21 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 15:58:30 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:20 --:--:-- 0curl: (52) Empty reply from server
Thu Nov 26 15:58:51 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0curl: (28) Operation timed out after 30001 milliseconds with 0 bytes received
Thu Nov 26 15:59:21 CET 2015
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- 0:00:29 --:--:-- 0curl: (28) Operation timed out after 30001 milliseconds with 0 bytes received
syslog extract (with tvheadend debug): http://slexy.org/view/s2RcOW7Wz8
It looks that oscam is stuck or that tvheadend doesn't even try to contact it... :-\
Updated by Jaroslav Kysela almost 9 years ago
I found it... Apply this oscam patch (with ubuf one).
Updated by Mario D almost 9 years ago
Chapeau! You did it again.
You already know but: you are my hero!
Updated by Jaroslav Kysela almost 9 years ago
- Status changed from New to Fixed
Both above oscam changes are in r11178 . Closing as fixed (in tvh and in oscam).