Bug #3346
closed
"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
Updated by Jaroslav Kysela almost 10 years ago
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 10 years ago
Trying to reproduce here, but without success yet...
Updated by Jaroslav Kysela almost 10 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 10 years ago
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 10 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 10 years ago
I found it... Apply this oscam patch (with ubuf one).
Updated by Mario D almost 10 years ago
Chapeau! You did it again.
You already know but: you are my hero!
Updated by Jaroslav Kysela almost 10 years ago
- Status changed from New to Fixed
Both above oscam changes are in r11178 . Closing as fixed (in tvh and in oscam).