OSCam hängt sich fast täglich auf

[Anton.Braun]

Hallo zusammen,

ich betreibe auf einem kleinen Intel NUC Server mit Debian 10.2 64bit (Kernel: Linux nuc 4.19.0-6-amd64 #1 SMP Debian 4.19.67-2+deb10u2 (2019-11-11) x86_64 GNU/Linux) u.a. OSCam für die Versorgung der heimischen Dreamboxen und einem PC mit einer HDPlus-Karte (HD01 im Argolis Smartreader V2). Dies funktioniert mittlerweile immer schlechter. Während vor Jahren noch alles stabil lief, steigt OSCam seit einigen Monaten fast täglich aus - es hängt sich einfach auf und reagiert nicht mehr auf Anfragen aus dem LAN, das Logfile bleibt stehen, der Prozess muss gekillt und der Dienst neu gestartet werden. Das Webinterface hingegen ist weiterhin erreichbar - zumindest solange, bis man auf die Idee kommt, den Reader (der HDPlus-Karte) dort zu deaktivieren und anschließend erneut zu aktivieren... dann hängt sich auch das Webinterface auf.

OSCam wird aus dem SVN aktuell gehalten, sprich das lokale Repository regelmäßig aktualisiert und das Binary gebaut (mittels make USE_LIBUSB=1), momentan OSCam 1.20_svn11570-x86_64-linux-gnu-libusb.

Ich finde in den System-Logfiles auch nichts, was auf die Ursache schließen lässt. Andere Dienste (Apache, Samba, FHEM, DNS, DHCP, ...) laufen problemlos weiter, nur OSCam zickt ´rum.

Spoiler: oscam.conf

[global]
waitforcards = 1
nice = -10
pidfile = /var/run/oscam.pid
logfile = /var/log/oscam.log;stdout
disablelogfile = 0
maxlogsize = 10240
lb_mode = 1
lb_save = 100
lb_savepath = /tmp/.oscam/stat
preferlocalcards = 2
disablecrccws_only_for = 0500:50F000;09C4:000000;098C:000000;098D:000000
clientmaxidle = 0
unlockparental = 1

[cs357x]
port = 15000

[dvbapi]
enabled = 1
au = 1
listen_port = 11500
user = haswell
boxtype = pc

[webif]
httpport = 8888
httphelplang = de
httpallowed = 127.0.0.1,10.81.0.0-10.81.0.255

Spoiler: oscam.server

[reader]
label = HDplus
description = orignal HD01 Karte für HD+
enable = 1
protocol = smartreader
device = SRv2;Serial:SMART001
caid = 1830
boxkey = A7...7C
rsakey = BF...D5
caid = 1830
ecmwhitelist = 1830:92
detect = cd
mhz = 534
autospped = 1
group = 1
emmcache = 1,1,10,0
blockemm-unknown = 1
auprovid = 003411
lb_weight = 300

Die Dinge, die auf den ersten Blick in der Konfiguration zu viel aussehen, lassen sich wie folgt erklären:
- disablecrccws_only_for und lb_* ist noch drin, da auch mal eine Sky-Karte verteilt wurde, kann mittlerweile wohl raus, halte ich aber als Problemursache für unwahrscheinlich.
- dvbapi ist der Zugriff für den PC. Dort läuft der DVBViewer mit entsprechendem Plugin, um auf OSCam zugreifen zu können.

Hat irgendjemand von euch eine Idee, warum sich OSCam aufhängt? Ich kann den Beginn des Problems leider nicht mehr genau eingrenzen, könnte mir aber Vorstellen, dass es mit dem Upgrade von Debian 9 auf 10 zusammenhängen könnte (neuer Kernel, neue glibc u.s.w.).

 

[surfbuster]

Bitte mal den log schicken, auch wenn du der Meinung bist er sagt nicht viel aus....

Ich gehe von aus, du hast glibc error.... sämtliche reader Killed und clients disconnected und kann dir schon mal sagen, am Kernel liegt es nicht.

 

[OnkelAtze]

Welchen NUC hast Du NUC8? I3 I5 I7?
Wie viele Klienten? Wenn viele nimm lb_save = 100 raus oder setze es deutlich höher...

Meine Konfiguration auf einem NUC8i3:

Spoiler: oscam.conf

[global]
nice = -1
netprio = 1
waitforcards = 0
preferlocalcards = 2
unlockparental = 1
maxlogsize = 4096
logfile = /tmp/oscam.log
failbantime = 1440
lb_mode = 1

[cs378x]
port = ***

[cccam]
port = ***
version = 2.3.2
reshare = 1
reshare_mode = 1

[webif]
httpport = ***
httpuser = ***
httppwd = ***
httphelplang = de
httppollrefresh = 1
httpshowmeminfo = 1
httpshowloadinfo = 1
httpallowed = 127.0.0.1,192.168.0.0-192.168.255.255

 

[Anton.Braun]

Ich habe einen NUC6I5SYH.

Das OSCam Logfile hört ja einfach auf - da steht nichts neues mehr drin, nur der letzte gültige Zugriff. Ich starte jetzt mal neu (Schreibfehler "autospped" ist behoben worden) und so würde es theoretisch aussehen - wobei im Echtbetrieb natürlich am Ende mehr steht. Es wird jetzt bis morgen oder übermorgen laufen und dann urplötzlich stehen bleiben:

Spoiler: oscam.log

Starting daemon: oscam.

-------------------------------------------------------------------------------
>> OSCam << cardserver log switched at Mon Dec 2 19:40:28 2019
-------------------------------------------------------------------------------
2019/12/02 19:40:28 00000000 s >> OSCam << cardserver log switched, version 1.20_svn, build r11570 (x86_64-linux-gnu-libusb)
2019/12/02 19:40:28 00000000 s (main) System name = Linux
2019/12/02 19:40:28 00000000 s (main) Host name = nuc
2019/12/02 19:40:28 00000000 s (main) Release = 4.19.0-6-amd64
2019/12/02 19:40:28 00000000 s (main) Version = #1 SMP Debian 4.19.67-2+deb10u2 (2019-11-11)
2019/12/02 19:40:28 00000000 s (main) Machine = x86_64
2019/12/02 19:40:28 00000000 s (config) services reloaded: 0 services freed, 2 services loaded, rejected 0
2019/12/02 19:40:28 00000000 s (config) userdb reloaded: 3 accounts loaded, 0 expired, 0 disabled
2019/12/02 19:40:28 00000000 s (main) signal handling initialized
2019/12/02 19:40:28 00000000 s (config) 19 provid's loaded
2019/12/02 19:40:28 00000000 s (config) 99 service-id's loaded in 0 ms
2019/12/02 19:40:28 00000000 s (net) cs357x: initialized (fd=5, port=15000)
2019/12/02 19:40:28 00000000 s (reader) HDplus [smartreader] creating thread for device SRv2;Serial:SMART001
2019/12/02 19:40:28 00000000 s (main) waiting for local card init
2019/12/02 19:40:28 14983EA8 h (webif) webif: decompressed 180738 bytes back into 446040 bytes
2019/12/02 19:40:28 14983EA8 h (webif) HTTP Server running. ip=0.0.0.0 port=8888
2019/12/02 19:40:28 509E84D3 r (reader) HDplus [smartreader] Reader initialized (device=SRv2;Serial:SMART001, detect=cd, mhz= AUTO, cardmhz=369)
2019/12/02 19:40:29 509E84D3 r (reader) HDplus [smartreader] card detected
2019/12/02 19:40:34 509E84D3 r (reader) HDplus [smartreader] ATR: 3F FF 95 00 FF 91 81 71 FE 47 00 44 4E 41 53 50 31 34 32 20 52 65 76 47 43 36 61
2019/12/02 19:40:34 509E84D3 r (reader) HDplus [smartreader] Effective reader settings mhz =534 F= 512 D= 16 N=0 T=1 inv=1 parity=ODD
2019/12/02 19:40:35 509E84D3 r (reader) HDplus [smartreader] detect native nagra card
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [smartreader] ready for requests
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [smartreader] found card system nagra
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] THIS WAS A SUCCESSFUL START ATTEMPT No 1 out of max allotted of 1
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] ROM: D N A S P 1 4 2
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] REV: R e v G C 6
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] SER: ############
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] CAID: 1830
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] Prv.ID: 00 00 34 11 (sysid)
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] Prv.ID: 00 00 00 00
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] IRD ID: ############
2019/12/02 19:40:38 509E84D3 r (reader) HDplus [nagra] active to: 2020/01/23 11:59
2019/12/02 19:40:39 509E84D3 r (reader) HDplus [nagra] -----------------------------------------
2019/12/02 19:40:39 509E84D3 r (reader) HDplus [nagra] |id |tier |valid from |valid to |
2019/12/02 19:40:39 509E84D3 r (reader) HDplus [nagra] +----+--------+------------+------------+
2019/12/02 19:40:39 509E84D3 r (reader) HDplus [nagra] |8011|0064 |2013/07/18 |2014/07/19 |
2019/12/02 19:40:39 509E84D3 r (reader) HDplus [nagra] |8011|0065 |2128/02/07 |2129/02/07 |
2019/12/02 19:40:39 509E84D3 r (reader) HDplus [nagra] |8011|0BEA |2016/08/12 |2017/08/12 |
2019/12/02 19:40:40 509E84D3 r (reader) HDplus [nagra] |8011|0BB8 |2019/06/17 |2020/01/21 |
2019/12/02 19:40:40 509E84D3 r (reader) HDplus [nagra] -----------------------------------------
2019/12/02 19:40:40 00000000 s (main) init for all local cards done
2019/12/02 19:40:40 00000000 s (emmcache) loaded 42 emmcache records from /tmp/.oscam/oscam.emmcache in 1 ms
2019/12/02 19:40:40 00000000 s (emmcache) loaded 42 emmstat records from /tmp/.oscam/oscam.emmstat in 0 ms
2019/12/02 19:40:40 0C6F4E0D c (client) plain dvbapi-client granted (haswell, au=on (1 reader))
2019/12/02 19:40:40 0C6F4E0D c (dvbapi) dvbapi channelcache loaded from /usr/local/etc/oscam.ccache
2019/12/02 19:40:40 0C6F4E0D c (dvbapi) Using TCP listen socket, API forced to DVBAPIv3 (0), userconfig boxtype: 11
2019/12/02 19:44:07 682E41B9 c (client) encrypted cs357x-client 10.81.0.22 granted (dm920, au=on (1 reader))
2019/12/02 19:44:07 682E41B9 c (camd35) dm920 emm-request sent (reader=HDplus, caid=1830, auprovid=003411)
2019/12/02 19:44:07 682E41B9 c (ecm) dm920 (1830@000000/0000/EF74/92:386AABD082F4771EECE6BCB88C69EF3E): found (447 ms) by HDplus (L/1/3/3) - SAT.1 HD
2019/12/02 19:44:10 682E41B9 c (ecm) dm920 (1830@000000/0000/EF74/92:EC2097123BB097906A3C6B14594515F7): found (447 ms) by HDplus (L/1/3/3) - SAT.1 HD
2019/12/02 19:44:25 682E41B9 c (ecm) dm920 (1830@000000/0000/EF74/92:959A823D4DF1F0B23778F32DB9AF9F59): found (447 ms) by HDplus (L/1/3/3) - SAT.1 HD

Als Client habe ich i.d.R. immer nur einen gleichzeitig laufen - DM920 im Wohnzimmer, DM820 im Schlafzimmer oder in ganz seltenen Fällen den PC.

Wenn ich jetzt im dmesg oder unter /var/log/syslog etwas sehen würde, würde ich es gerne posten - aber da ist Ruhe, was das Thema USB oder OSCam angeht. Keine relevanten Fehler.
Dabei sei ggf. noch erwähnt, dass ich beispielsweise abends die Dreambox und mich schlafen lege und erst am nächsten (oder übernächsten) Abend wieder zu Hause im Wohnzimmer bin und es dann oft nicht mehr läuft, man den Absturz zeitlich also nicht eingrenzen kann. Andererseits ist es gelegentlich aber so, dass alles nach dem Einschalten der Dreambox noch ein paar Minuten läuft und OSCam dann erst abstürzt. Das sind dann die Momente, ich denen es Sinn macht, alle Logfiles zu durchforsten - aber da ist dann nichts.

Den angesprochenen glibc-Error... wo würde ich den sehen, wenn nicht im Syslog?

Ich habe heute schon versucht, ein fertiges Binary zu laden und alternativ zu testen, doch das hier zuletzt angebotene (für x86-amd64-pc (o.ä.)) hat leider keine USB-Smartreader-Unterstützung.

 

[surfbuster]

Ich vermute jetzt mal, du hast eine box mit den selben Zugangsdaten..... irgend wo in deinen Hause......die verursacht den regelmäßigen Absturz

 

[Anton.Braun]

Box im Sinne von Dreambox? Die beiden Boxen haben jeweils einen eigenen Zugang, ebenso der PC:

Spoiler: oscam.user

[account]
user = dm820
pwd = dm820
group = 1,2,3
au = HDplus

[account]
user = dm920
pwd = dm920
group = 1,2,3
au = HDplus

[account]
user = haswell
pwd = haswell
group = 1,2,3
cccstealth = 1
au = HDplus

In der oscam.server der beiden Dreamboxen stehen jeweils die eigenen Zugangsdaten drin. Der PC ist zu Zeiten des Absturz immer aus gewesen (der läuft nur maximal einmal pro Woche).

Aber selbst wenn dies ein Problem wäre, würde ich einen entsprechenden Fehler im Logfile erwarten. Deine Theorie würde ich vorsichtig ausschließen. Was ich aber mal ausprobieren werde: Die DM820 im Schalfzimmer, die eigentlich 100% der Woche im StandBy ist, komplett ausschalten - dann ist nur die DM920 im Wohnzimmer in der Lage, mit OSCam zu kommunizieren und kein anderes Gerät kann (theoretisch) dazwischen grätschen.

 

[OnkelAtze]

ich würde lb_save = 100 in
#lb_save = 100
ändern und mal schauen was passiert...

 

[Anton.Braun]

Also ECMs nicht mehr für die Statistik speichern? Da das lb_* Zeug momentan sowieso unwichtig ist, kann ich das so gerne mal ausprobieren (bevor ich alles deaktiviere und man danach nicht schlauer ist).

Wobei ich weiterhin davon überzeugt bin, dass OSCam auch einfach "zwischendurch" abstürzt, ohne dass irgendein Client darauf zugreift.

 

[OnkelAtze]

Wie startest Du OSCam auf dem NUC?

über Service?

Spoiler: teste mal

[Unit]
Description=OScam
After=network.target
Requires=network.target

[Service]
Type=forking
PIDFile=/var/run/oscam.pid
ExecStart=/usr/bin/oscam -b -B /var/run/oscam.pid -c /usr/oscam -p 512
ExecStop=/bin/rm /var/run/oscam.pid
TimeoutStopSec=1
Restart=always
RestartSec=5
StartLimitInterval=0

[Install]
WantedBy=multi-user.target

damit sollte OSCam neu starten, wenn es abstürzt...

OSCam config Pfad /usr/oscam ggf. anpassen

 

[ghost0815]

Ich habe heute schon versucht, ein fertiges Binary zu laden und alternativ zu testen, doch das hier zuletzt angebotene (für x86-amd64-pc (o.ä.)) hat leider keine USB-Smartreader-Unterstützung.

OScam Self-made (kompilieren)

Originalpost @ Streamboard-wiki Intro Nachfolgend wird der Weg vom Auschecken bis hin zur kompilierten OSCam im Groben beschrieben. Alle aufgeführten Linux-Beispiele und Code-Fragmente wurden auf einem Linux-PC mit Debian 6 getestet. Umgebung Ein Linux-PC wird vorausgesetzt...

www.digital-eliteboard.com

 

[Anton.Braun]

@ghost0815 Bis jetzt baue ich ja selbst (siehe ganz oben), aber um einen eventuell dort vorhandenen Fehler (v.a. der Libraries) auszuschließen, würde ich alternativ mal ein extern gebautes Binary ausprobieren.

@OnkelAtze aus historischen Gründen noch per Init-Skript:

Spoiler: /etc/init.d/oscam

#!/bin/bash

### BEGIN INIT INFO
# Provides: oscam
# Required-Start: $local_fs $network
# Required-Stop: $local_fs $network
# Default-Start: 2 3 4 5
# Default-Stop: 0 1 6
# Short-Description: Init script for oscam
### END INIT INFO

#. /lib/lsb/init-functions

NAME=oscam
USER=oscam
DAEMON="/usr/local/bin/oscam"
DAEMON_OPTS="-b"
NICELEVEL=-10

start() {
echo -n "Starting daemon: "$NAME
echo > /var/log/oscam.log
chown oscam /var/log/oscam.log
touch /var/log/oscam.log-prev
chown oscam /var/log/oscam.log-prev
touch /var/log/oscamuser.log
chown oscam /var/log/oscamuser.log
start-stop-daemon --chuid $USER --nicelevel $NICELEVEL --start --quiet --exec $DAEMON -- $DAEMON_OPTS
echo "."
}

stop() {
echo -n "Stopping daemon: "$NAME
killall oscam
#start-stop-daemon --chuid $USER --stop --quiet --oknodo --pidfile $PIDFILE
#rm $PIDFILE
echo "."
}

restart(){
stop
sleep 3
start
}

status(){
pidof $DAEMON > /dev/null 2>&1
RETVAL=$?
if [ $RETVAL -ne 0 ]; then
echo "$NAME is not running"
exit $RETVAL
else
echo "$NAME is running"
fi
}

reload(){
kill -1 $(cat $PIDFILE)
RETVAL=$?
if [ $RETVAL -eq 0 ]; then
echo "$NAME reloading successfully"
else
echo "$NAME reloading failed"
exit $RETVAL
fi
}

case "$1" in
start)
start
;;
stop)
stop
;;
restart)
restart
;;
reload)
reload
;;
status)
status
;;
*)
echo "Usage: $0 {start|stop|restart|reload|status}"
exit 1
esac

exit 0

Die Alternative über systemd kann ich morgen gerne mal implementieren, ist eigentlich sowieso Zeit für den Umstieg (auf dem betroffenen System). Kann ich jetzt nur nicht mal "eben so" machen, da das Init-Skript in diversen Diensten eingebunden ist, um im Fall der Fälle OSCam "einfach" neu zu starten (Button auf Smartphone, Alexa, ...).

 

[bl0w]

Ein Disk-Platz bzw RAM problem hast du nicht?

 

[Anton.Braun]

Nee.... 16 GB RAM (kaum genutzt, es sei denn, virtuelle Maschinen fahren gelegentlich (1-2x pro Monat) mal hoch), CPU-Last liegt i.d.R. bei 0,1 bis 0,2, HDD ist Platz ohne Ende (auf allen Mount-Points). Wie gesagt, der "Server" hat noch mehr Aufgaben und da läuft alles problemlos und steht ebenso unter Beobachtung.

Bringen irgendjemandem hier die Ausgaben von strace auf die beiden existierenden OSCam-Prozesse etwas, wenn es "hängt" (wobei der "Vaterprozess" auch im laufenden Betrieb nur ein wait4 auf die Kind-PID hat)?

 

[Anton.Braun]

Es ist mal wieder so weit. Zwischenzeitlich hatte ich das Binary ausgetauscht, diesmal mittels SimpleBuild-Skript gebaut. Wenn ich mit strace auf den Prozess gehe, sehe ich noch Anfragen der Dreambox (10.81.0.22), OSCam reagiert darauf aber nicht und schreibt auch nichts in´s Logfile.

Spoiler: strace

poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 0 (Timeout)
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\303\35\250\200\273FK4\305Bw\6\327u\323wL\250\177\365;\234\"8\217\223 \304\305N;T"..., 1021, 0, {sa_family=AF_INET, sin_port=htons(41162), sin_addr=inet_addr("10.81.0.22")}, [16]) = 180
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 0 (Timeout)
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\303\35\250\200\266\313,\21\216~\r\365|\230%\342A\213\231\2\3249\26\326\365#\7n_\201\211\310"..., 1021, 0, {sa_family=AF_INET, sin_port=htons(41162), sin_addr=inet_addr("10.81.0.22")}, [16]) = 180
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\303\35\250\200\305\r\333\0r\307\221\3515\0014\27\247\247\260\365i%\2453\25\265\237b&q}\325"..., 1021, 0, {sa_family=AF_INET, sin_port=htons(41162), sin_addr=inet_addr("10.81.0.22")}, [16]) = 164
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 0 (Timeout)
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 0 (Timeout)
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\303\35\250\200\362fc\363\302\316,\225~\34\341o\36\f\205l\312|r\305\250XUh\370-\373h"..., 1021, 0, {sa_family=AF_INET, sin_port=htons(41162), sin_addr=inet_addr("10.81.0.22")}, [16]) = 196
poll([{fd=17, events=POLLIN|POLLPRI}, {fd=5, events=POLLIN|POLLPRI}], 2, 5000) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "\303\35\250\200\255\300\256t\337.\226\257(\203\245\202\36ME\251\206\31\250D9'\211'jW\232D"..., 1021, 0, {sa_family=AF_INET, sin_port=htons(41162), sin_addr=inet_addr("10.81.0.22")}, [16]) = 196