FernetMenta / vdr-plugin-vnsiserver

VDR plugin to handle XBMC clients.
GNU General Public License v2.0
16 stars 33 forks source link

vdr: message repeated 99 times: [ [1857] VNSI: close video input #49

Closed jpg73 closed 8 years ago

jpg73 commented 8 years ago

Dear FernetMenta, Let me share one issue I've My config is ubuntu14.04+VDR2.2(same issue with 2.3.1)+VNSI1.10.10 + Kodi (15 or 16 or 17) on HW side, TBS6991 +CAM + legal subscription I define my list of channels(SD/HD : FTA or Scrambled) and works The issue is the following, If I switch to a channels not covered by my subscription and come back after on official channel, the Zapping time is very high( up to 40sec instead of few secs) and I've the following Apr 15 22:19:54 streamy3 vdr: [1831] CAM 1: assigned to device 1 Apr 15 22:19:54 streamy3 vdr: [1831] VNSI: Successfully found following device: 0x955a20 (1) for receiving Apr 15 22:19:54 streamy3 vdr: [1831] VNSI: Successfully switched to channel 7 - La2_h12721 Apr 15 22:19:54 streamy3 vdr: [1831] VNSI: Started streaming of channel La2_h12721 (timeout 10 seconds) Apr 15 22:19:54 streamy3 vdr: [1855] device 1 receiver thread started (pid=1608, tid=1855, prio=high) Apr 15 22:19:54 streamy3 vdr: [1857] cLiveStreamer stream processor thread started (pid=1608, tid=1857, prio=high) Apr 15 22:19:54 streamy3 vdr: [1858] device 1 TS buffer thread started (pid=1608, tid=1858, prio=high) Apr 15 22:19:55 streamy3 vdr: [1856] VNSI: VideoInput: no pat/pmt within timeout, falling back to channel pids Apr 15 22:19:55 streamy3 vdr: [1856] VNSI: Video Input - new pmt, attaching receiver Apr 15 22:19:55 streamy3 vdr: [1857] VNSI: Created stream for pid=552 and type=8 Apr 15 22:19:55 streamy3 vdr: [1857] VNSI: Created stream for pid=102 and type=2 Apr 15 22:19:55 streamy3 vdr: [1857] VNSI: Created stream for pid=52 and type=11 Apr 15 22:19:57 streamy3 vdr: [1629] frontend 0/0 lost lock on channel 7 (La2_h12721), tp 112721 Apr 15 22:19:58 streamy3 vdr: [1629] frontend 0/0 regained lock on channel 7 (La2_h12721), tp 112721 Apr 15 22:19:59 streamy3 vdr: [1855] detaching receiver - won't decrypt channel S19.2E-53-1119-12852 with CAM 1 Apr 15 22:19:59 streamy3 vdr: [1855] VNSI: call retune ... Apr 15 22:19:59 streamy3 vdr: [1855] CAM 1: unassigned Apr 15 22:19:59 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:19:59 streamy3 vdr: [1857] VNSI: call retune ... Apr 15 22:19:59 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:19:59 streamy3 vdr: [1858] device 1 TS buffer thread ended (pid=1608, tid=1858) Apr 15 22:19:59 streamy3 vdr: [1855] buffer stats: 18236 (0%) used Apr 15 22:19:59 streamy3 vdr: [1855] device 1 receiver thread ended (pid=1608, tid=1855) Apr 15 22:19:59 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:20:00 streamy3 vdr: message repeated 13 times: [ [1857] VNSI: close video input ...] Apr 15 22:20:00 streamy3 vdr: [1629] frontend 0/0 lost lock on channel 7 (La2_h12721), tp 112721 Apr 15 22:20:00 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:20:01 streamy3 vdr: message repeated 8 times: [ [1857] VNSI: close video input ...] Apr 15 22:20:01 streamy3 vdr: [1629] frontend 0/0 regained lock on channel 7 (La2_h12721), tp 112721 Apr 15 22:20:01 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:20:04 streamy3 vdr: message repeated 25 times: [ [1857] VNSI: close video input ...] Apr 15 22:20:04 streamy3 vdr: [1857] VNSI: Channel: scrambled 3 Apr 15 22:20:04 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:20:14 streamy3 vdr: message repeated 99 times: [ [1857] VNSI: close video input ...] Apr 15 22:20:14 streamy3 vdr: [1857] VNSI: Channel: no data 16 Apr 15 22:20:14 streamy3 vdr: [1857] VNSI: close video input ... Apr 15 22:20:15 streamy3 vdr: message repeated 8 times: [ [1857] VNSI: close video input ...] Apr 15 22:20:15 streamy3 vdr: [1857] CAM 1: assigned to device 1 Apr 15 22:20:15 streamy3 vdr: [1857] VNSI: Successfully found following device: 0x955a20 (1) for receiving Apr 15 22:20:15 streamy3 vdr: [1865] device 1 receiver thread started (pid=1608, tid=1865, prio=high) Apr 15 22:20:15 streamy3 vdr: [1867] device 1 TS buffer thread started (pid=1608, tid=1867, prio=high) Apr 15 22:20:15 streamy3 vdr: [1630] VNSI: Video Input - new pmt, attaching receiver syslog.zip

I guess it's an issue with VNSI (not the TBS driver or VDR) ... What did you advice ?

Thanks in advance JP

FernetMenta commented 8 years ago

please set vdr logging level to 3 and pastebin log

jpg73 commented 8 years ago

Hi, The attached syslog, is already with vdr -l 3 ... or maybe I miss something ? Thanks JP

FernetMenta commented 8 years ago

I hope you understand that I don't download logfiles.

jpg73 commented 8 years ago

Hi, Sorry to contact you, but I didn’t understand what you request :-( (sorry I’m poor HW guy) the VDR launched is already with -l 3 option (vdr -l 3 -d -P live -P xmltv2vdr -P vnsiserver -v /recordings -c /tmp/datas_buffer/vdr -E /tmp/datas_buffer/epg --chartab=ISO-8859-15 --user=vdr)

I put zipped file of syslog in the git (because not allowed to put syslog file alone) I pasted last sentences of this syslog in the git…

Thanks in advance for your help JP

On 17 Apr 2016, at 11:16, Rainer Hochecker notifications@github.com wrote:

I hope you understand that I don't download logfiles.

— You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub https://github.com/FernetMenta/vdr-plugin-vnsiserver/issues/49#issuecomment-210983896

meier2meier commented 8 years ago

Hi JP!

Have a look at http://pastebin.com.

Br

Am 17.04.2016 um 11:25 schrieb jpg73 notifications@github.com:

Hi, Sorry to contact you, but I didn’t understand what you request :-( (sorry I’m poor HW guy) the VDR launched is already with -l 3 option (vdr -l 3 -d -P live -P xmltv2vdr -P vnsiserver -v /recordings -c /tmp/datas_buffer/vdr -E /tmp/datas_buffer/epg --chartab=ISO-8859-15 --user=vdr)

I put zipped file of syslog in the git (because not allowed to put syslog file alone) I pasted last sentences of this syslog in the git…

Thanks in advance for your help JP

On 17 Apr 2016, at 11:16, Rainer Hochecker notifications@github.com wrote:

I hope you understand that I don't download logfiles.

— You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub https://github.com/FernetMenta/vdr-plugin-vnsiserver/issues/49#issuecomment-210983896

— You are receiving this because you are subscribed to this thread. Reply to this email directly or view it on GitHub

jpg73 commented 8 years ago

Thanks a lot

http://pastebin.com/bhKAPHZh

I hope it's done in the correct way Again Apologies for my poor knowledge

FernetMenta commented 8 years ago

please comment on the scenario. how should I know what channels are covered by your subscription and what are not. what did you do when recording the log? what did you observe? what did you expect to happen?

jpg73 commented 8 years ago

Hi, First of all , thank for your patience about this issue scenario is extracted from a complex one, but with this the bug is perfectly reproduced 1/ VDR freshly rebooted 2/ Kodi launched on PC 3/ start to tune Q_11185 channel which is not supported by my subscription ...Kodi informs channels is scrambled -> OK 4/ after roughly 10sec , I tune to other channel La2_h12721 .Which is supported by my subs. 5/ in this sequence , Kodi takes from 30 -50sec to show the descrambled channel (in stead of 2-3sec)

In the opposite, when I switch from/to any channels handled by subscription.I didn't observe any issue.

Thanks in advance JP

FernetMenta commented 8 years ago

VDR is a bit nasty in this regard. Is has a hard set scrambling timeout that disconnects the receiver after only 3 sec if no descrambled packets arrives within this time. VNSI can only try to retune. I can try some tweaks. Are you able to compile from source?

jpg73 commented 8 years ago

'sure VDR 2.3.0 +VNSI was tried with your advices founded on web!

FernetMenta commented 8 years ago

could you try branch "test" https://github.com/FernetMenta/vdr-plugin-vnsiserver/tree/test there is a new setting "DisableScrambleTimeout". Set this to true

jpg73 commented 8 years ago

compilation OK ! but is a compilation setting ? or some option to launch with vdr -l 3 -d -P live -P vnsiserver ... ?? maybe vnsiserver.DisableScrambleTimeout = 1 in setup.conf ? Thanks

FernetMenta commented 8 years ago

vnsiserver.DisableScrambleTimeout

yes, but much easier with VDR UI. You can a bring up VDR ui for configuration in Kodi with settings->tv->client specific. navigate to vdr setup->plugins and you'll find this new setting.

jpg73 commented 8 years ago

Hi, your setting remove "VNSI: close video input" message , but now I've a lot of ... Apr 17 22:17:43 streamy3 vdr: [1893] VNSI: Channel: no data 16 Apr 17 22:17:53 streamy3 vdr: [1893] VNSI: Channel: no data 16

then to summary now, 1/If I switch to "channel 1"not supported by my subs 2/the first next "channel2" (handled by my subscription) generate a no data 16 3/the second, unlock totally the situation ... and perfectly descramble a "channel3" The crispy story ... if I go back on "channel2" ... no problem at all :-(

It's obvious it's not a VNSI issue ... what did you advice ? driver Issue or VDR issue ? Thanks JP

FernetMenta commented 8 years ago

please pastebin a log and comment on the scenario.

jpg73 commented 8 years ago

Hi,
Here is the pastebin http://pastebin.com/QJ0ff7R6 About the scenario 1/ fresh boot up 2/ launch VDR2.3 +VNSI with DisableScrambleTimeout set to true 3/ launch KODI and select La2_h12721 4/ Select Fr3_h11681HOTB -> Perfectly descrambled 5/ Select Q_11185_KO (which is not handled by my subscription) 6/ Select La2_h12721 -> Kodi refuse to descramble (with supported by my subscription 7/ Select Fr3_h11681HOTB -> Perfectly descrambled 8/ Select La2_h12721 -> and ... it works !!!

Where did you think the issue comes ? VNSI ? VDR ? TBS Drivers ?

Thanks again for your envolvment JP

FernetMenta commented 8 years ago

did 3/ result in success?

jpg73 commented 8 years ago

it's strange, the first zap , is always not perfect.Let 's say NO Regards JP

FernetMenta commented 8 years ago

that's really strange because the log shows no issues for first zap. I would have expected logs like "scrambled" or "no data" but there is nothing like this after: Apr 18 20:40:52 streamy3 vdr: [1845] VNSI: Video Input - new pmt, attaching receiver

Could you pastebin kodi.log for this scenario?

Either I do something wrong or scrambled data passes through.

jpg73 commented 8 years ago

I replay all for perfect alignement between each logs Scenario still the same Kodi Log : http://pastebin.com/0frwc4P2 Server Log : http://pastebin.com/u82LJkrh

THX a lot

FernetMenta commented 8 years ago

Apr 18 22:20:53 streamy3 vdr: [1819] ERROR: unknown config parameter: vnsiserver.DisableScrambleTimeout = 1

I am wondering if you compiled the correct branch. Do you see this new parameter in the VDR UI?

jpg73 commented 8 years ago

Oh yes, 1/I try first to set in setup.conf

But seems not taken into account by VDR

2/ Now I saw this param in VDR UI & it’s set to true

(did you need snapshot ?)

Regards

JP

From: Rainer Hochecker [mailto:notifications@github.com] Sent: 18 April 2016 23:23 To: FernetMenta/vdr-plugin-vnsiserver vdr-plugin-vnsiserver@noreply.github.com Cc: jpg73 jp.guarrera@gmail.com Subject: Re: [FernetMenta/vdr-plugin-vnsiserver] vdr: message repeated 99 times: [ [1857] VNSI: close video input (#49)

Apr 18 22:20:53 streamy3 vdr: [1819] ERROR: unknown config parameter: vnsiserver.DisableScrambleTimeout = 1

I am wondering if you compiled the correct branch. Do you see this new parameter in the VDR UI?

— You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub https://github.com/FernetMenta/vdr-plugin-vnsiserver/issues/49#issuecomment-211586880 https://github.com/notifications/beacon/AJldDpGk9R2E_5IjKrizawczWODh2TLWks5p4_YWgaJpZM4IJG7p.gif

FernetMenta commented 8 years ago

I forced pushed an update to branch test (reset --hard). Please run the scenario again and pastebin syslog and kodi.log

jpg73 commented 8 years ago

Hi , I’m lost, what ’ve to do ? git update ? & new compilation ? Thanks

On 19 Apr 2016, at 19:59, Rainer Hochecker notifications@github.com wrote:

I forced pushed an update to branch test (reset --hard). Please run the scenario again and pastebin syslog and kodi.log

— You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub https://github.com/FernetMenta/vdr-plugin-vnsiserver/issues/49#issuecomment-212044309

FernetMenta commented 8 years ago

Get the new version from branch "test", and compile it. I squashed some changes. Means if you normally do "git pull", that won't work. This requires "get fetch" and "git reset --hard".

jpg73 commented 8 years ago

Here are the logs ... Kodi : http://pastebin.com/eZTZknea Syslog: http://pastebin.com/5NwKJzgp Same scenario Thanks

FernetMenta commented 8 years ago

Sorry, I did a mistake and the config parameter was not parsed properly. I updated branch test. Could you try again please.

jpg73 commented 8 years ago

I'm glad to see, I'm not alone creating mistakes ;-) Here are logs Kodi : http://pastebin.com/TKTeCwH6 Syslog : http://pastebin.com/LZnyUnDU Same Scenario, but at step 3 & 6, instead of "black screen" with descrambled channe info l. I see degraded channels (lot of Big pixel) BUT again step 4,7,8 work perfectly ! Thanks

FernetMenta commented 8 years ago

I have changed logging messages and this makes me sure that you are not running latest version of my branch "test" https://github.com/FernetMenta/vdr-plugin-vnsiserver/commit/0b0e26f877681ea5ce6fd8b7541f34af1ac2a49a

jpg73 commented 8 years ago

Could you tell me , what Ive to do more ? root@streamy3p:/home/jp/vdr23/vdr-plugin-vnsiserver# git pull Auto-merging videoinput.c CONFLICT (content): Merge conflict in videoinput.c Automatic merge failed; fix conflicts and then commit the result. root@streamy3p:/home/jp/vdr23/vdr-plugin-vnsiserver# git fetch root@streamy3p:/home/jp/vdr23/vdr-plugin-vnsiserver# git reset --hard HEAD is now at d30bbaf bump version to 1.4.0

FernetMenta commented 8 years ago

This is why I mentioned that "git pull" won't work. I never use this command and would vote to ban it from the planet :) I assume you have only a single remote repo that points to this one here. Verify with: git remote -v In general this repo is named "origin". do git fetch origin git reset --hard origin/test

the last command sets your current branch to be equal to my branch "test"

jpg73 commented 8 years ago

root@streamy3p:/home/jp/vdr23/vdr-plugin-vnsiserver# git remote -v origin https://github.com/FernetMenta/vdr-plugin-vnsiserver (fetch) origin https://github.com/FernetMenta/vdr-plugin-vnsiserver (push) root@streamy3p:/home/jp/vdr23/vdr-plugin-vnsiserver# git fetch origin root@streamy3p:/home/jp/vdr23/vdr-plugin-vnsiserver# git reset --hard origin/test HEAD is now at 73069e0 squash me

Is it OK , with this ? ready to compile ?Thanks

FernetMenta commented 8 years ago

this looks good

jpg73 commented 8 years ago

Here is ... Kodilog : http://pastebin.com/k6rshbya Syslog : http://pastebin.com/b7C6t6Rm

Same Scenario, but at step 6, instead of "black screen" with descrambled channe info l. I see degraded channels (lot of Big pixel) BUT again step 4,7,8 work perfectly ! Now Step 3 is OK ... Thanks

FernetMenta commented 8 years ago

could you try setting PMT timeout to 5 sec?

jpg73 commented 8 years ago

no significant changes , let's say it's worst with PMT=5 (instead of PMT=1) :-(

jpg73 commented 8 years ago

I feel we are not so far to the solution, Is there any other parameter to check on VDR level ?

jpg73 commented 8 years ago

I ve feeling some channels "block" the CAM and some channels "unlock" the situation ...

jpg73 commented 8 years ago

Smal observation, FOR La2_h12721 the exact frequency is 12721.75 and Fr3_11681 the exact frequency is 11681 .Then the same If I try to defineLa2_h12721 with frequency of 12722 ... the result is worst than with frequency of 12721. Is there a way define the exact frequency ? How VDR round it ? Thanks JP

FernetMenta commented 8 years ago

Could you please post a log with pmt timeout > 5

jpg73 commented 8 years ago

with PMT=8 Logs are Kodi:http://pastebin.com/rGFmXZr1 Server: http://pastebin.com/pMi6kHxD Same scenario, same observations

X10 thanks

FernetMenta commented 8 years ago

The log looks fine. VDR thinks the stream gets descrambled because the scramble flag is reset. Then the still scrambled stream produces lots of decoder error in Kodi. My guess is that the CAM does something wrong. What happens if you press stop after 5 and then start La2_h12721?

jpg73 commented 8 years ago

If I stop after 5 and start on LA2 , produced the same than step 3 ... not perfectly descrambled (big pixels or image partially green)

FernetMenta commented 8 years ago

now I am confused:

Now Step 3 is OK ...

you said step 3 was ok? Is it ok or not?

jpg73 commented 8 years ago

result for step 3 vary from PMT ( bad with PMT=8 & PMT=5) -> not perfectly descrambled (big pixels or image partially green) With PMT=1 : it is the same but after 20-30 sec, the image becomes clear (without any action)

FernetMenta commented 8 years ago

I am not in the mood to give up :) Could you please try the new version I pushed to branch test.

jpg73 commented 8 years ago

no changes :-( logs are(for PMT=1) Kodi : http://pastebin.com/nmTZacVw Server : http://pastebin.com/pqpbU6Tw I think you have to continue in this direction ... I believe in you Best...

FernetMenta commented 8 years ago

how is the first switch now?

jpg73 commented 8 years ago

bad ... totally unreadable :-(

FernetMenta commented 8 years ago

please do another run with the new parameter "disablescrambletimeout" disabled. also make sure that priority (vnsi config setting in kodi) is set to 0. then we get the same sequence of action as vdr does when it starts a recording.