[Gelöst] TVH/Oscam dekodiert manche Programme nur noch nach Oscam Neustart

Also: Es blieb NICHT so. Am nächsten Tag waren die Problem wieder da!

Ich bin das ganze jetzt nochmal systematisch von vorne angegangen und denke ich bin weiter:

• Ich wusste zwar aus den Oscam Logs, dass Oscam irgendwann nachts den Socket "verliert", aber nicht wann, weil die default [definition='1','0']log[/definition] Grösse mit 10kb schlicht zu klein war. Habe das auf 500kb erhöht, um mal über 24h mitzuloggen. Die Oscam "Socket unknown" Messages fingen letzte Nacht um 00:09 an.
• Dann bin ich in den Syslog des Servers gegangen und habe gesehen, dass um ziemlich genau 00:09 mein Unifi Dream Machine Pro Gateway Ärger macht. Hier die Log-Meldung:
  
  
  Brainfuck: OMV Syslog

  Sep 11 00:09:01 MyRS CRON[1586]: (root) CMD ( [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
  Sep 11 00:09:06 MyRS systemd[1]: Starting Clean php session files...
  Sep 11 00:09:06 MyRS systemd[1]: phpsessionclean.service: Succeeded.
  Sep 11 00:09:06 MyRS systemd[1]: Started Clean php session files.
  Sep 11 00:09:39 MyRS rsyncd[1963]: forward name lookup for unifi.local failed: Name or service not known
  Sep 11 00:09:39 MyRS rsyncd[1963]: connect from UNKNOWN (192.168.1.1)
  Sep 11 00:09:44 MyRS smbd[1966]: [2020/09/11 00:09:44.986037, 0] ../source3/smbd/process.c:335(read_packet_remainder)
  Sep 11 00:09:44 MyRS smbd[1966]: read_fd_with_timeout failed for client 192.168.1.1 read error = NT_STATUS_END_OF_FILE.

• Die UDMP Events sind voll von UDMP disconnect messages. Also vermute ich das Problem mittlerweile tatsächlich im Gateway. Ich bin bisher auf der 1.7.2 Firmware geblieben, weil es zur neuen 1.8.0 gemischtes Feedback gab, habe jetzt aber mal upgegraded. Vielleicht hilft das. Wenn nicht, baue ich die UDMP aus, und das alte USG 3G wieder ein.

@noob_at_pc Mich würde Deine Perspektive hierzu sehr interessieren, weil ich weiss, dass Du Dich damit auskennst. Vielleicht hast Du noch eine Idee, wie ich die UDMP Seite besser analysieren kann, um das Problem weiter einzuschränken.

Danke fürs reinschauen @noob_at_pc. Ich rate schon seit geraumer Zeit nur noch ins Blaue...

Hier nochmal kurz von vorne: Im normalen Betrieb wartet oder "horcht" der Oscam Container auf Anfragen vom TVH Container, verschlüsselte Kanäle zu entschlüsseln. Das ganze läuft über Port 9000. Ist auch normalerweise kein Problem. Wenn ich über TVH ein verschlüsseltes Programm starte, schickt TVH die Anfrage über Port 9000 an Oscam. Der entschlüsselt und reicht den entschlüsselten Stream an TVH zurück. Dann kann ich das Programm über TVH sehen. Bei mir ist es aber regelmässig so, dass diese Port 9000 Verbindung zwischen TVH und Oscam irgendwann abbricht. Sehe ich im Oscam Log, weil dort "unknown socket" Fehlermeldungen kommen. Dann hilft nur noch ein Neuaufbau der Verbindung, entweder über Oscam-Neustart oder TVH-Neustart (egal), damit es wieder geht.

Um dem Problem weiter auf den Grund zu gehen, habe ich mir den Syslog meines OMV Servers angeschaut, auf dem die beiden Docker Container mit TVH und Oscam laufen, und festgestellt, dass JEDESMAL wenn Oscam die Verbindung auf Port 9000 verliert, im OMV syslog folgender Eintrag auftaucht:

Sep 11 00:09:44 MyRS smbd[1966]: [2020/09/11 00:09:44.986037, 0] ../source3/smbd/process.c:335(read_packet_remainder)
Sep 11 00:09:44 MyRS smbd[1966]: read_fd_with_timeout failed for client 192.168.1.1 read error = NT_STATUS_END_OF_FILE.

Der "Client" 192.168.1.1 ist die UDMP, die halt auch sämtlichen Netzwerktraffic zw. den Oscam und TVH Containern "abwickelt". Deswegen vermute ich (mittlerweile) ein Netzwerk-Problem, entweder auf dem Server, oder aber am Gateway. Was ich NICHT weiss, ist, ob die Fehler im OMV Syslog kausal für die Oscam/TVH Probleme, oder "nur" koinzident sind. Weiss aber nicht, wie ich von hier am besten weiter analysieren kann...

Zu Deiner Frage: Die UDMP hängt an einem 24er Unifi managed POE Switch (Gen 1), und daran hängt der Server mit je zwei Ports im Bond. Nein, Kabel und Ports habe ich noch nicht getauscht, aber ansonsten habe ich auch keine Netzwerkprobleme. Syslog auf dem Server: s.o.

Hoffe das ist klarer. Noch eine Idee?

TVH läuft auf Docker im Host Mode. Oscam läuft auf Docker im Bridge Mode, und damit m.E. in einem anderen (virtuellen) Netz:

Hier ein Beispiel für das oscam.[definition='1','0']log[/definition] per pastebinit: http://paste.ubuntu.com/p/tH66RGqvnK/
Du kannst sehen, wie Oscam einige Zeit idled, und dann plötzlich die "unknown socket" Fehler losgehen.

Die dazu synchronen log-Einträge auf dem Server habe ich ja schon mehrfach gepostet. Hier aber auch nochmal im Detail der Output von systemctl status smbd:

● smbd.service - Samba SMB Daemon
Loaded: loaded (/lib/systemd/system/smbd.service; enabled; vendor preset: enabled)
Active: active (running) since Sat 2020-09-12 22:07:02 CEST; 22h ago
Docs: man:smbd(8)
man:samba(7)
man:smb.conf(5)
Main PID: 1998 (smbd)
Status: "smbd: ready to serve connections..."
Tasks: 7 (limit: 4915)
Memory: 24.4M
CGroup: /system.slice/smbd.service
├─ 1998 /usr/sbin/smbd --foreground --no-process-group
├─ 2001 /usr/sbin/smbd --foreground --no-process-group
├─ 2002 /usr/sbin/smbd --foreground --no-process-group
├─ 2200 /usr/sbin/smbd --foreground --no-process-group
├─ 2221 /usr/sbin/smbd --foreground --no-process-group
├─10039 /usr/sbin/smbd --foreground --no-process-group
└─32614 /usr/sbin/smbd --foreground --no-process-group
Sep 12 22:07:02 MyRS.local systemd[1]: Starting Samba SMB Daemon...
Sep 12 22:07:02 MyRS.local smbd[1998]: [2020/09/12 22:07:02.268971,  0] ../lib/util/become_daemon.c:138(daemon_ready)
Sep 12 22:07:02 MyRS.local smbd[1998]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
Sep 12 22:07:02 MyRS.local systemd[1]: Started Samba SMB Daemon.                                                        
Sep 12 22:07:05 MyRS.local systemd[1]: /lib/systemd/system/smbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/smbd.pid → /run/samba/smbd.pid; please update the unit file accordingly.
Sep 13 12:26:32 MyRS.local smbd[16754]: [2020/09/13 12:26:32.298743,  0] ../source3/smbd/process.c:335(read_packet_remainder)
Sep 13 12:26:32 MyRS.local smbd[16754]:   read_fd_with_timeout failed for client 192.168.1.1 read error = NT_STATUS_END_OF_FILE.

Sag bitte einfach Bescheid, wenn Du mehr brauchst...

Oscam war mein erster Verdacht. Hatte entsprechend im digital-eliteboard schon um Hilfe gebeten (siehe erster Post). Dort haben wir Oscam auf links gekrempelt, aber das war es nicht.

Ist aber gut, wenn Du die UDMP ausschliessen kannst. Dann knöpfe ich mir den OMV Server vor. Dort gab es eine Reihe von Updates in letzter Zeit...

Der Fehler tritt jeden Tag mittags um die gleiche Zeit auf. Cron Jobs, die auf die Zeit hindeuten habe ich nicht gefunden. Ich hab jetzt mal den [definition='1','0']log[/definition] Level von Samba auf dem Server erhöht, um Hinweise auf die Ursache zu finden. So sieht's aus: https://pastebin.com/hbQpys2M
Die Verbindung zwischen den Containern bricht um genau 12:27:49 ab. Das Log deckt diese Zeit, die Zeit unmittelbar davor und danach ab.

Bin echt für jeden Hinweis zur Ursache oder weiteren Debugging-Möglichkeiten dankbar.

Und @DeBaschdi: Sorry, dass ich Dir noch nicht geantwortet habe. Dein Workaround-Vorschlag wäre sicher eine Möglichkeit, gerade jetzt wo ich den Zeitpunkt kenne. Ich würde aber lieber dem Grundproblem auf den Grund gehen. An ein Hardware-Problem glaube ich mittlerweile auch nicht mehr, weil das Problem reproduzierbar jeden Tag um ungefähr die gleiche Zeit auftritt...

Danke fürs Reinschauen! Hier der Output von testparm:

OMV nutzt omv-salt, um die Konfigurationen konsistent zu halten. Habe ich dafür auch genutzt. Insofern müsste(!!!) das eigentlich passen.

Zu Deiner Frage "Read error im Log file". Ich würde das verstehen, wenn hier einer meiner Laptops oder PCs versuchen würde auf die SMB Shares zuzugreifen. Was ich aber nicht verstehe, ist, dass die Zugriffe von 192.168.1.1 erfolgen. Das ist die IP Adresse meiner Unifi Dream Machine Pro (UDMP), die als Gateway agiert, aber auch als "Mini-Server" für Kameraüberwachungssysteme. Die Aufnahmen dafür laufen allerdings auf eine Disk, die in der UDMP selbst installiert ist. Ich kann mich nicht erinnern, auf der UDMP jemals Zugriffe auf die samba shares meines Servers konfiguriert zu haben.

Der Punkt SMB1-Problem sagt mir nichts. Kannst Du mehr dazu sagen, bitte?

Danke für Eure Ideen!

Ich glaube eigentlich auch nicht, dass Samba Ursache für die Verbindungsfehler ist, aber schon, dass beide Probleme die gleiche Ursache haben. Ich beobachte die Fehler seit vielen Tagen, und die tauchen immer genau zur gleichen Zeit auf.

@malvinas2: Ja, ist halt ein "Multifunktionsgerät". Ich bin die Configs mehrmals durchgegangen und denke(!) die sind ok. Kann aber nichts mehr ausschliessen...
@noob_at_pc: Vielen Dank für den Link. Die Idee über eine Socket-Datei statt über die Netzwerk-Ports zu gehen ist super. Das werde ich definitiv ausprobieren! Zum möglichen Bridge-Problem: Weisst Du wie ich das prüfen kann?
@Acid_Rain: Ich habe das alte Gateway noch im Schrank, und den alten Controller im Docker (ist nur angehalten). Insofern ist ein Austausch eigentlich relativ machbar. Muss ich nur auf ein Wochenende warten, wo ich Zeit dafür habe (frühestens in 2 Wochen)...

Nochmals Danke. Ich gehe mal über die Socket-Datei und schaue, ob das Problem dann weg ist...

Gut, ich hatte TVH und Oscam heute Morgen - wie im verlinkten Thread beschrieben - auf Socket-Connection umgestellt. Ging relativ problemlos.

Die Samba-Fehler tauchten um 12:27 auch heute wieder auf. Insofern war die TVH und Oscam Verbindung sicher nicht ursächlich dafür.
Die Socket-Verbindung zwischen TVH und Oscam bleibt bestehen. Ich kann danach ein Programm tunen und descramblen.

Leider ist es jetzt so, dass nur das erste, manchmal das zweite tunen noch klappt. Danach spuckt TVH "Service instance is bad" Fehlermeldungen aus. Das Oscam [definition='1','0']log[/definition] bleibt still. Ich habe auch gesehen, dass im TVH Setting für pc-nodmx Verbindungen "Problematic" davor steht. Hat perexg Mitte 2018 committed. Ich werde echt noch wahnsinnig. Ich glaube ich bin in der Trueman Show und das ist irgendein Test... :-S

Guter Punkt. Danke Dir. Ist "historisch" gewachsen. Ich hatte früher Sat>IP Server, die das benötigt haben. Mittlerweile habe ich aber DD Devices im Server selbst, sodass ich das nicht mehr brauche. Habe den TVH Container nun gelöscht und im Bridge-Mode komplett neu angelegt. Oscam und TVH kommunizieren über TCP nur noch intern über die Brücke. Hatte erstmal Probleme, weil Portainer in der Bridge ebenfalls auf Port 9000 läuft. Habe Oscam und TVH nun auf Port 9009 umkonfiguriert, und in TVH die interne Bridge IP von Oscam eingetragen. Soweit, so gut. Jetzt erstmal TV schauen. Meine Familie läuft schon Amok. Um 12:27 morgen Mittag weiss ich mehr...