Unicable sid nicht in pat

[Jule_666]

Hi!
Hab mir ein GT-S3SCR4 LNB zugelegt. Hat 3x Legacy und 1x Unicable. Habe das Problem, dass bei Unicable nach dem Umschalten häufig die Meldung (sid nicht in pat) kommt, schalte ich um, ist alles wieder ok, auch wenn ich auf den Sender der vorher nicht lief zurück schalte läuft der dann. Den LNB bzw. den Hersteller GT-Sat (max technologies) kann man bei den Unicable-Einstellungen nicht auswählen... Hab alles mögliche ausprobiert aber leider geht´s entweder gar nicht oder halt wie beschrieben. Kenne mich mit Unicable noch nicht wirklich aus. Wo kann das Problem liegen? Treiber? Oder doch ne falsche Einstellung? Hmm...

[morly]

Hm... kenn mich mit Unicable auch nicht aus,
aber vielleicht bekommst mehr Infos im Log?
Brauchst nicht unbedingt seriell loggen - mach einfach via telnet ein:

setconsole

und schau was zusätzlich ausgegeben wird wenn der Fehler kommt

[Jule_666]

Gut, usb2serial-Adapter hab ich heute verliehen...

Hier der die Consolenausgabe:

IPBOX910:~# setconsole
IPBOX910:~# data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 00A2006C
****        37379 6 ****
[SEM] UP
KEY_PRESS - 6c 6
++++            0 ms ++++
playing 1:0:19:283D:3FB:1:C00000:0:0:0:
[eDVBCAService] free slot 0 demux 0 for service 1:0:19:2B66:3F3:1:C00000:0:0:0:
[eDVBCAService] free service 1:0:19:2B66:3F3:1:C00000:0:0:0:
data[0] 0xe0, data[1] 0xff
decoder state: play, vpid=-1, apid=-1
DEMUX_STOP - pcr - ok
DEMUX_STOP - video - ok
VIDEO_STOP - KEY_RELEASE - 6c 00 6 6 CAUSE=Timeout
----          151 ms ----
[SEM] DOWN
ok
AUDIO_STOP - ok
DEMUX_STOP - audio - ok
AUDIO_CONTINUE - ok
DEMUX_STOP - ttx - ok
TuxTxt stopped service 17f2
cleaning up
TuxTxt cache cleared
start release channel timer
[__evStart]
[__evSeekableStatusChanged]
not pauseable.
not pauseable.
RemovePopup, id = ZapError
[eDVBLocalTimerHandler] remove channel 0x1f7db38
[eEPGCache] remove channel 0x1f7db38
allocate channel.. 03fb:0001
(0)tune
[prepare] UnicableTuningWord 0x996
[prepare] guard_offset 0
RotorCmd ffffffff, lastRotorCmd ffffffff
prepare_sat System 1 Freq 11493750 Pol 0 SR 22000000 INV 2 FEC 2 orbpos 192 system 1 modulation 2 pilot 2, rolloff 0
tuning to 1280 mhz
OURSTATE: tuning
allocate Channel: res 0
[eDVBCIInterfaces] addPMTHandler 1:0:19:283D:3FB:1:C00000:0:0:0:
allocate demux
[SEC] invalidate current switch params
set sequence pos 3
[SEC] setVoltage 2
[SEC] setTone 0
[SEC] sleep 20ms
[SEC] sendDiseqc: e0105a0996(?)
[SEC] sleep 50ms
[SEC] setVoltage 1
[SEC] update current switch params
[SEC] startTuneTimeout 5000
[SEC] setFrontend 1
setting frontend 0
(0)fe event: status 0, inversion off, m_tuning 1
(0)fe event: status 1, inversion off, m_tuning 2
[SEC] sleep 500ms
(0)fe event: status 1f, inversion off, m_tuning 3
OURSTATE: ok
[eDVBLocalTimerHandler] channel 0x2e559eb0 running
[eEPGCache] channel 0x2e559eb0 running
[EPGC] next update in 2 sec
stop release channel timer
ok ... now we start!!
eventNewProgramInfo 0 0
have 1 video stream(s) (13ed), and 1 audio stream(s) (13ee), and the pcr pid is 13ed, and the text pid is 13f0
allocate demux
TuxTxt cache cleared
decoder state: play, vpid=5101, apid=5102
DMX_SET_PES_FILTER(0x13ed) - pcr - ok
DMX_SET_PES_FILTER(0x13ee) - audio - ok
AUDIO_SET_BYPASS(1) - ok
AUDIO_PLAY - ok
Video Device: /dev/dvb/adapter0/video0
demux device: /dev/dvb/adapter0/demux0
VIDEO_SET_STREAMTYPE 1 - ok
DMX_SET_PES_FILTER(0x13ed) - video - ok
VIDEO_PLAY - ok
DMX_SET_PES_FILTER(0x13f0) - ttx - ok
TuxTxt cache cleared
TuxTxt: initialized
TuxTxt service started 13f0
VIDEO_CONTINUE - ok
VIDEO_SLOWMOTION(0) - ok
VIDEO_FAST_FORWARD(0) - ok
AUDIO_CONTINUE - ok
disable teletext subtitles
TuxTxt running thread...(13f0)
[__evUpdatedInfo]
[writeChannelName]
vfd display text: Das Erste HD
[showCrypted]
[showDolby]
[showMp3]
[eDVBCAService] new service 1:0:19:283D:3FB:1:C00000:0:0:0:
[eDVBCAService] add demux 0 to slot 0 service 1:0:19:283D:3FB:1:C00000:0:0:0:
[__evUpdatedEventInfo]
[__evUpdatedEventInfo]
[__evUpdatedEventInfo]
PATready
no PAT entry found.. start delay
FE_GET_PROPERTY failed (Invalid argument)
ignore sdt update data.... incorrect transponder tuned!!!
DVB service failed to tune - error 3
RemovePopup, id = ZapError
AddPopup, id = ZapError
[EPGC] start caching events(1377194053)
crc32 failed! is 557f9163

[eDVBLocalTimerHandler] diff is 0
[eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
[eDVBLocalTimerHandler] not changed
Timeout!
[EPGC] abort non avail schedule other reading
[EPGC] abort non avail netmed schedule reading
[EPGC] abort non avail netmed schedule other reading
[EPGC] abort non avail FreeSat schedule_other reading
[EPGC] abort non avail viasat reading
[EPGC] nownext finished(1377194061)
[EPGC] schedule finished(1377194068)
[EPGC] stop caching events(1377194068)
[EPGC] next update in 60 min

[morly]

jetzt noch ein log beim erfolgreichen Umschalten bitte

[Jule_666]

Das ist leider nicht so einfach... Geht eigentlich nur jeder 2. Umschaltversuch gut...
Der Log ist von RTLNitro auf ZDFHD (fehlgeschlagen) und dann weiter auf Das ErsteHD (funktioniert)

pRead < 00330067
****           52 11 ****
++++           45 ms ++++
data[0] 0xe0, data[1] 0xff
KEY_RELEASE - 67 00 11 11 CAUSE=Timeout
----          154 ms ----
[SEM] DOWN
data[0] 0xe0, data[1] 0x1f
160 - OK
pRead < 00340160
****         1449 12 ****
[SEM] UP
KEY_PRESS - 160 12
++++            3 ms ++++
playing 1:0:19:2B66:3F3:1:C00000:0:0:0:
[eDVBCAService] free slot 0 demux 0 for service 1:0:1:2F1D:441:1:C00000:0:0:0:
[eDVBCAService] free service 1:0:1:2F1D:441:1:C00000:0:0:0:
data[0] 0xe0, data[1] 0x1f
160 - OK
pRead < 00340160
****           53 12 ****
decoder state: play, vpid=-1, apid=-1
DEMUX_STOP - pcr - ok
DEMUX_STOP - video - data[0] 0xe0, data[1] 0x1f
160 - OK
pRead < 00340160
****           46 12 ****
ok
VIDEO_STOP - data[0] 0xe0, data[1] 0x1f
160 - OK
pRead < 00340160
****           50 12 ****
++++            3 ms ++++
data[0] 0xe0, data[1] 0xff
ok
AUDIO_STOP - KEY_RELEASE - 160 00 12 12 CAUSE=Timeout
----          151 ms ----
[SEM] DOWN
ok
DEMUX_STOP - audio - ok
AUDIO_CONTINUE - ok
DEMUX_STOP - ttx - ok
TuxTxt stopped service 54
cleaning up
TuxTxt cache cleared
start release channel timer
[__evStart]
[__evSeekableStatusChanged]
not pauseable.
not pauseable.
RemovePopup, id = ZapError
[eDVBLocalTimerHandler] remove channel 0x1f9ed88
[eEPGCache] remove channel 0x1f9ed88
allocate channel.. 03f3:0001
(0)tune
[prepare] UnicableTuningWord 0x963
[prepare] guard_offset 0
RotorCmd ffffffff, lastRotorCmd ffffffff
prepare_sat System 1 Freq 11361750 Pol 0 SR 22000000 INV 2 FEC 2 orbpos 192 system 1 modulation 2 pilot 2, rolloff 0
tuning to 1208 mhz
OURSTATE: tuning
allocate Channel: res 0
[eDVBCIInterfaces] addPMTHandler 1:0:19:2B66:3F3:1:C00000:0:0:0:
allocate demux
set sequence pos 3
[SEC] setVoltage 2
[SEC] setTone 0
[SEC] sleep 20ms
[SEC] sendDiseqc: e0105a0963(?)
[SEC] sleep 50ms
[SEC] setVoltage 1
[SEC] update current switch params
[SEC] startTuneTimeout 5000
[SEC] setFrontend 1
setting frontend 0
(0)fe event: status 0, inversion off, m_tuning 1
(0)fe event: status 1, inversion off, m_tuning 2
[SEC] sleep 500ms
[DVBCAHandler] no more services
OURSTATE: failed, retune
(0)tune
[prepare] UnicableTuningWord 0x963
[prepare] guard_offset 0
RotorCmd ffffffff, lastRotorCmd ffffffff
prepare_sat System 1 Freq 11361750 Pol 0 SR 22000000 INV 2 FEC 2 orbpos 192 system 1 modulation 2 pilot 2, rolloff 0
tuning to 1208 mhz
OURSTATE: tuning
tune failed.
DVB service failed to tune - error 1
RemovePopup, id = ZapError
AddPopup, id = ZapError
ignore sdt update data.... incorrect transponder tuned!!!
set sequence pos 3
set sequence pos 7
[SEC] invalidate current switch params
[SEC] sendDiseqc: e00000(DiSEqC reset)
[SEC] sleep 50ms
[SEC] sendDiseqc: e00003(DiSEqC peripherial power on)
[SEC] sleep 150ms
[SEC] sendDiseqc: e01038f0(?)
[SEC] sleep 50ms
[SEC] sleep 70ms
[SEC] sendDiseqc: e01038f0(?)
[SEC] sleep 50ms
set sequence pos 3
[SEC] setVoltage 2
[SEC] setTone 0
[SEC] sleep 20ms
[SEC] sendDiseqc: e0105a0963(?)
[SEC] sleep 50ms
[SEC] setVoltage 1
[SEC] update current switch params
[SEC] startTuneTimeout 5000
[SEC] setFrontend 1
setting frontend 0
data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 0035006C
****         7509 13 ****
[SEM] UP
KEY_PRESS - 6c 13
++++            0 ms ++++
data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 0035006C
****           50 13 ****
data[0] 0xe0, data[1] 0xff
++++          103 ms ++++
KEY_RELEASE - 6c 00 13 13 CAUSE=Timeout
----          151 ms ----
[SEM] DOWN
(0)fe event: status 0, inversion off, m_tuning 1
(0)fe event: status 1, inversion off, m_tuning 2
[SEC] sleep 500ms
data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 0036006C
****         3860 14 ****
[SEM] UP
KEY_PRESS - 6c 14
++++            0 ms ++++
playing 1:0:19:283D:3FB:1:C00000:0:0:0:
data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 0036006C
****           49 14 ****
start release channel timer
data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 0036006C
****           50 14 ****
[__evStart]
[__evSeekableStatusChanged]
not pauseable.
not pauseable.
RemovePopup, id =data[0] 0xe0, data[1] 0x1b
6C - DOWN
pRead < 0036006C
****           49 14 ****
 ZapError
[eDVBLocalTimerHandler] remove channel 0x1f9ed88
[eEPGCache] remove channel 0x1f9ed88
++++            4 ms ++++
allocate channel.. 03fb:0001
(0)tune
[prepare] UnicableTuningWord 0x984
[prepare] guard_offset 0
RotorCmd ffffffff, lastRotorCmd ffffffff
prepare_sat System 1 Freq 11493750 Pol 0 SR 22000000 INV 2 FEC 2 orbpos 192 system 1 modulation 2 pilot 2, rolloff 0
tuning to 1208 mhz
allocate Channel: res 0
[eDVBCIInterfaces] addPMTHandler 1:0:19:283D:3FB:1:C00000:0:0:0:
allocate demux
set sequence pos 3
[SEC] setVoltage 2
[SEC] setTone 0
data[0] 0xe0, data[1] 0xff
KEY_RELEASE - 6c 00 14 14 CAUSE=Timeout
----          152 ms ----
[SEM] DOWN
[SEC] sleep 20ms
[SEC] sendDiseqc: e0105a0984(?)
[SEC] sleep 50ms
[SEC] setVoltage 1
[SEC] update current switch params
[SEC] startTuneTimeout 5000
[SEC] setFrontend 1
setting frontend 0
(0)fe event: status 0, inversion off, m_tuning 1
(0)fe event: status 1, inversion off, m_tuning 2
[SEC] sleep 500ms
(0)fe event: status 1f, inversion off, m_tuning 3
OURSTATE: ok
[eDVBLocalTimerHandler] channel 0x1f9ed88 running
[eEPGCache] channel 0x1f9ed88 running
[EPGC] next update in 2 sec
stop release channel timer
ok ... now we start!!
eventNewProgramInfo 0 0
have 1 video stream(s) (13ed), and 1 audio stream(s) (13ee), and the pcr pid is 13ed, and the text pid is 13f0
allocate demux
TuxTxt cache cleared
decoder state: play, vpid=5101, apid=5102
DMX_SET_PES_FILTER(0x13ed) - pcr - ok
DMX_SET_PES_FILTER(0x13ee) - audio - ok
AUDIO_SET_BYPASS(1) - ok
AUDIO_PLAY - ok
Video Device: /dev/dvb/adapter0/video0
demux device: /dev/dvb/adapter0/demux0
VIDEO_SET_STREAMTYPE 1 - ok
DMX_SET_PES_FILTER(0x13ed) - video - ok
VIDEO_PLAY - ok
DMX_SET_PES_FILTER(0x13f0) - ttx - ok
TuxTxt cache cleared
TuxTxt: initialized
TuxTxt service started 13f0
VIDEO_CONTINUE - ok
VIDEO_SLOWMOTION(0) - ok
VIDEO_FAST_FORWARD(0) - ok
AUDIO_CONTINUE - ok
disable teletext subtitles
TuxTxt running thread...(13f0)
[__evUpdatedInfo]
[writeChannelName]
vfd display text: Das Erste HD
[showCrypted]
[showDolby]
[showMp3]
[eDVBCAService] new service 1:0:19:283D:3FB:1:C00000:0:0:0:
[eDVBCAService] add demux 0 to slot 0 service 1:0:19:283D:3FB:1:C00000:0:0:0:
[__evUpdatedEventInfo]
[__evUpdatedEventInfo]
[__evUpdatedEventInfo]
[eDVBLocalTimerHandler] diff is -1
[eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
[eDVBLocalTimerHandler] update RTC
[eDVBLocalTimerHandler] time update to 20:09:22
[eDVBLocalTimerHandler] m_time_difference is -1
[eDVBLocalTimerHandler] set Linux Time
VIDEO_GET_EVENT - ok
unhandled DVBAPI Video Event 9
PATready
use pmtpid 13ec for service_id 283d
eventNewProgramInfo 0 0
Rds PID 13f4 detected ? ! ?
have 1 video stream(s) (13ed), and 3 audio stream(s) (13ee, 13ef, 13f2), and the pcr pid is 13ed, and the text pid is 13f0
decoder state: play, vpid=5101, apid=5102
Rds PID 13f4 detected ? ! ?
[__evUpdatedInfo]
[writeChannelName]
vfd display text: Das Erste HD
[showCrypted]
[showDolby]
[showMp3]
[eDVBCIInterfaces] gotPMT
[eDVBCAService] don't build/send the same CA PMT twice
[__evUpdatedEventInfo]
[__evUpdatedInfo]
[writeChannelName]
vfd display text: Das Erste HD
[showCrypted]
[showDolby]
[showMp3]
VIDEO_GET_EVENT - ok
unhandled DVBAPI Video Event 5
VIDEO_GET_EVENT - ok
[__evVideoSizeChanged]
VIDEO_GET_EVENT - ok
AITready
[EPGC] start caching events(1377194963)
FE_GET_PROPERTY failed (Invalid argument)
crc32 failed! is b50ce74b

crc32 failed! is 35980230

sdt update done!
OCready
[EPGC] abort non avail schedule other reading
[EPGC] abort non avail netmed schedule reading
[EPGC] abort non avail netmed schedule other reading
[EPGC] abort non avail FreeSat schedule_other reading
[EPGC] abort non avail viasat reading
[EPGC] nownext finished(1377194972)

[morly]

OK - was natürlich auffällt ist:

PATready
no PAT entry found.. start delay
FE_GET_PROPERTY failed (Invalid argument)
ignore sdt update data.... incorrect transponder tuned!!!
DVB service failed to tune - error 3

... no PAT entry found... aber warum?

[Jule_666]

Gute Frage... Also am LNB selber glaub ich nicht dass es liegt. Empfang hab ich über 90 % und über Legacy ist alles ok.

[Jule_666]

So, Problem (hoffentlich) gelöst
Ich hab mir gedacht dass es irgendwo ein Timingproblem geben muss. Also dass der Tuner etwas abfragt, was der LNB so schnell nicht zur Verfügung stellen kann. Hab dann heute Morgen vor der Arbeit (das hätte mir sonst keine Ruhe gelassen )angefangen mit den Satellitenausrüstungseinstellungen rum zu spielen. Einfach mal alles auf 1000 ms hochgeschraubt was nicht mit Motor zu tun hatte und siehe da, es klappte. Nur hat das Umschalten sehr lange gedauert. Dann alle Einstellungen nach und nach auf Default zurück...

Das hier hat das Problem gelöst:

Delay after last diseqc command von Defalut 20 auf 80 erhöhen.
Bei 70 gibt es das Problem immer noch, bei 80 ist es dauerhaft weg. Powerzappen kein Problem mehr.

Nach nem Reboot/Boot hab ich dann festgestellt, dass es häufiger zu Tunen fehlgeschlagen kommt. Hab jetzt einfach mal das hier gemacht:
Delay after change voltage before switch command 80
Delay after enable voltage before switch command 500

Nach den Reboots/Boots mit diesen Einstellungen war das Bild immer da.

Im Ergebnis stell ich für mich fest, dass die Satellitenausrüstungseinstellungen im Image "suboptimal" sind, soweit man unicable nutzt. Ob das jetzt speziell nur mit meinem LNB ist kann ich natürlich nicht beurteilen.

Werde das aber mal weiter beobachten und falls es noch Probleme gibt weiterbasteln und dann natürlich auch hier berichten.

EDIT:
Könnte jemand vielleicht noch diesen Eintrag in die unicable.xml (im Bereich lnb) an der passenden Stelle Hinzufügen?

- <manufacturer name="GT-SAT">
 <product name="GT-S3SCR4" scr1="1210" scr2="1420" scr3="1680" scr4="2040" /> 

 </manufacturer>