[VLCKit] tvOS issues

[ssbmaccom]

Hi,
I got a couple of issues inside my free tvOS App (vuplusTV) using VLCKit, which currently is in beta for Version 1.1.

I have posted one issue about AC-3/Dolby Audio streams already in the "Development around libVLC" area - but it did not get any attention yet:https://forum.videolan.org/viewtopic.ph ... 93dc30345a
Maybe I get support now

Second issue is about playback of streams from encrypted TV Channel like SKY or HD+:
Several testers reported to me, that they get freezes every about 100 seconds, when playing back the streams. Other Apps and VLC on a PC do not have this issue. To make sure, the issue is not caused by the CI+ module (SKY V14, paired), I asked my testers to record a stream and check if playback of the recording shows the same issue. And it does on my App, other tvOS apps, that likely also use VLCKit or libVLC for playback. The recorded stream is not encrypted anymore, as it plays fine with VLC for PC after ftp'ing it to the PC - so the CI+ module is not required anymore.
Well, why always 100 seconds?
I asked if someone can share such a recording (TS file) for further analysis. Waiting for response now.

Third issue is about playback of recorded TS-Streams:
When trying to playback recorded streams via http from the STB, very often the playback starts without video, only Audio. Pausing playback and then continuing it works then, Video and Audio are fine then. This happens even with SD streams.
I use VLCKit for playback. I create an instance of VLCKit and set the media, which is a http URL. Then is (now) use parseWithOptions:6 and wait for the delegate callback didFinishParsing: before I send the play command in a background Thread with a brief delay. The delay helped a bit, but even a delay of up to 2 seconds does not solve it. The parsing state is 1 == completed, skipped.
I even tried to send play, pause and play with a brief delay, which does not solve this as well.
Any suggestion welcome.

I can share code snippets if this helps...

[ssbmaccom]

About second issue I will open a new thread, as VLC for tvOS shows the same behavior.
On my iPad (first Retina generation) the video does not run at all.

[Jean-Baptiste Kempf]

Well, the reason is that the TS are badly reencoded.

[ssbmaccom]

How can you prove that without having a look at it?
Indeed, VLC for Mac has no issues, VLC for tvOS has issues.
Kodi play them back fine, some others as well - just some VLCKit based do not?

And a dead lock (starting after 86 second and resuming after additional 86 seconds) looks quite strange... Dead locks should not happen.
Can you recommend any TS stream tool to evaluate your assumption?

[Jean-Baptiste Kempf]

How can you prove that without having a look at it?
Indeed, VLC for Mac has no issues, VLC for tvOS has issues.
Kodi play them back fine, some others as well - just some VLCKit based do not?

And a dead lock (starting after 86 second and resuming after additional 86 seconds) looks quite strange... Dead locks should not happen.
Can you recommend any TS stream tool to evaluate your assumption?

Show the logs. But this is similar to a different complaint with TS demuxer in 3.0

[ssbmaccom]

ok, how to get access to the logs created by VLC for tvOS?

[fkuehne]

You can enable debug logging on the VLCLibrary instance associated with your player instance.

[ssbmaccom]

OK, I can try that with my App - the log should be inside the Apps document folder - I will check.

How to access the log created by VLC for tvOS?

BTW: have you received the upload of the stream?

Cheers, SSB

[fkuehne]

As I tried to say, you need to do

Code: Select all

VLCMediaPlayer *player = [[VLCMediaPlayer alloc] init]; player.libraryInstance.debugLogging = YES;

to have VLC log everything to the normal Xcode or device console.

Sample was received and propagated to the respective engineer.

[ssbmaccom]

OK, I once did this. But how to enable it with VLC, when not having built it on my local Machine, but using the AppStore Version?
I will check the debug logs anyway

[fkuehne]

There is no way to enable debug logging for the VLC-iOS binary from the store.

[ssbmaccom]

OK, here we go with the log.

Code: Select all

2016-07-20 21:40:17.235354 vuplusTV[274:98165] [DYMTLInitPlatform] platform initialization successful 2016-07-20 21:40:17.926346 vuplusTV[274:98060] [User Defaults] Failed to read values in CFPrefsPlistSource<0x1700fef80> (Domain: group.de.schmidt-bilkenroth.vuplusTV, User: kCFPreferencesAnyUser, ByHost: Yes, Container: (null)): Using kCFPreferencesAnyUser with a container is only allowed for System Containers, detaching from cfprefsd :BouquetsViewControll: 68: EPG refresh at 21:45 2016-07-20 21:40:48.250343 vuplusTV[274:98060] creating player instance with private library as options were given 2016-07-20 21:40:48.283662 vuplusTV[274:98060] VLC media player - 3.0.0-git Vetinari 2016-07-20 21:40:48.283889 vuplusTV[274:98060] Copyright © 1996-2016 the VideoLAN team 2016-07-20 21:40:48.283989 vuplusTV[274:98060] revision 2.2.0-git-7411-g5c389a2 2016-07-20 21:40:48.284086 vuplusTV[274:98060] configured with /Users/ssb/Projekte/ssb/AppleTV/VLCKit/MobileVLCKit/ImportedSources/vlc/configure '--prefix=/Users/ssb/Projekte/ssb/AppleTV/VLCKit/MobileVLCKit/ImportedSources/vlc/install-ios-AppleTVOS/arm64' '--host=aarch64-apple-darwin11' '--with-contrib=/Users/ssb/Projekte/ssb/AppleTV/VLCKit/MobileVLCKit/ImportedSources/vlc/contrib/AppleTV-aarch64-apple-darwin11-aarch64' '--enable-static' '--disable-debug' '--enable-dvbpsi' '--enable-avcodec' '--disable-vpx' '--disable-neon' '--disable-macosx' '--disable-macosx-qtkit' '--disable-macosx-eyetv' '--disable-macosx-vlc-app' '--disable-macosx-avfoundation' '--disable-audioqueue' '--disable-shared' '--enable-macosx-quartztext' '--enable-mkv' '--enable-opus' '--disable-faad' '--disable-lua' '--disable-a52' '--enable-fribidi' '--disable-qt' '--disable-skins2' '--disable-vcd' '--disable-vlc' '--disable-vlm' '--disable-httpd' '--disable-nls' '--disable-sse' '--disable-notify' '--enable-live555' '--enable-realrtsp' '--enable-swscale' '--disable-projectm' '--enable-l 2016-07-20 21:40:48.286555 vuplusTV[274:98372] meta ok for (null), need to fetch art 2016-07-20 21:40:48.287012 vuplusTV[274:98374] looking for meta fetcher module matching "any": 0 candidates 2016-07-20 21:40:48.287114 vuplusTV[274:98374] no meta fetcher modules 2016-07-20 21:40:48.287214 vuplusTV[274:98374] searching art for 100 2016-07-20 21:40:48.287346 vuplusTV[274:98374] looking for art finder module matching "any": 1 candidates 2016-07-20 21:40:48.287773 vuplusTV[274:98374] no art finder modules matched 2016-07-20 21:40:48.287872 vuplusTV[274:98374] art not found for 100 2016-07-20 21:40:49.281701 vuplusTV[274:98381] Creating an input for '20160624 0255 - Sky Cinema HD - Ant-Man.ts' 2016-07-20 21:40:49.283473 vuplusTV[274:98382] using timeshift granularity of 50 MiB 2016-07-20 21:40:49.283658 vuplusTV[274:98382] using default timeshift path 2016-07-20 21:40:49.284001 vuplusTV[274:98382] `http://root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts' gives access `http' demux `' path `root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts' 2016-07-20 21:40:49.284179 vuplusTV[274:98382] specified demux: any 2016-07-20 21:40:49.284664 vuplusTV[274:98382] creating demux: access='http' demux='any' location='root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts' file='(null)' 2016-07-20 21:40:49.284841 vuplusTV[274:98382] looking for access_demux module matching "http": 3 candidates 2016-07-20 21:40:49.284938 vuplusTV[274:98382] no access_demux modules matched 2016-07-20 21:40:49.285418 vuplusTV[274:98382] creating access: http://root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts 2016-07-20 21:40:49.285900 vuplusTV[274:98382] looking for access module matching "http": 19 candidates 2016-07-20 21:40:49.295420 vuplusTV[274:98385] resolving 192.168.42.42 ... 2016-07-20 21:40:49.296906 vuplusTV[274:98385] connecting to 192.168.42.42 port 80 ... 2016-07-20 21:40:49.300464 vuplusTV[274:98382] outgoing request: GET /file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts HTTP/1.1 Host: 192.168.42.42:80 Accept: */* Accept-Language: en_US User-Agent: VLC/3.0.0-git LibVLC/3.0.0-git Range: bytes=0- 2016-07-20 21:40:49.314642 vuplusTV[274:98382] incoming response: HTTP/1.1 401 Unauthorized Date: Wed, 20 Jul 2016 19:40:48 GMT Content-Length: 149 Content-Type: text/html; charset=utf-8 WWW-Authenticate: Basic realm="OpenWebif" Server: TwistedWeb/13.2.0 Set-Cookie: TWISTED_SESSION=cd11a220d96c81c3c032df383ebebcec; Path=/ 2016-07-20 21:40:49.316200 vuplusTV[274:98382] querying proxy for http://root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts 2016-07-20 21:40:49.316493 vuplusTV[274:98382] no proxy 2016-07-20 21:40:49.316660 vuplusTV[274:98382] http: server='192.168.42.42' port=80 file='/file' 2016-07-20 21:40:49.316774 vuplusTV[274:98382] user='root' 2016-07-20 21:40:49.316912 vuplusTV[274:98382] Password in a URI is DEPRECATED 2016-07-20 21:40:49.317633 vuplusTV[274:98382] net: connecting to 192.168.42.42 port 80 2016-07-20 21:40:49.321753 vuplusTV[274:98382] connection succeeded (socket = 4) 2016-07-20 21:40:49.736106 vuplusTV[274:98382] HTTP answer code 206 2016-07-20 21:40:49.736569 vuplusTV[274:98382] this frame size=634584412 2016-07-20 21:40:49.738100 vuplusTV[274:98382] stream size=634584412,pos=0,remaining=634584412 2016-07-20 21:40:49.738435 vuplusTV[274:98382] Server: TwistedWeb/13.2.0 2016-07-20 21:40:49.740434 vuplusTV[274:98382] Content-Type: video/MP2T 2016-07-20 21:40:49.740846 vuplusTV[274:98382] We have a Cookie we won't remember: TWISTED_SESSION=61f489e22ca6168d8ec8da807570779c; Path=/ 2016-07-20 21:40:49.742103 vuplusTV[274:98382] using access module "http" 2016-07-20 21:40:49.742562 vuplusTV[274:98382] looking for stream_filter module matching "prefetch,cache_read": 8 candidates 2016-07-20 21:40:49.746339 vuplusTV[274:98382] Using stream method for AStream* 2016-07-20 21:40:49.746834 vuplusTV[274:98382] starting pre-buffering 2016-07-20 21:40:49.748404 vuplusTV[274:98382] received first data after 1 ms 2016-07-20 21:40:49.748637 vuplusTV[274:98382] pre-buffering done 1024 bytes in 0s - 562 KiB/s 2016-07-20 21:40:49.748745 vuplusTV[274:98382] using stream_filter module "cache_read" 2016-07-20 21:40:49.749840 vuplusTV[274:98382] looking for stream_filter module matching "any": 8 candidates 2016-07-20 21:40:49.750018 vuplusTV[274:98382] no stream_filter modules matched 2016-07-20 21:40:49.750542 vuplusTV[274:98382] looking for stream_filter module matching "record": 8 candidates 2016-07-20 21:40:49.750663 vuplusTV[274:98382] using stream_filter module "record" 2016-07-20 21:40:49.751833 vuplusTV[274:98382] creating demux: access='http' demux='ts' location='root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts' file='(null)' 2016-07-20 21:40:49.752379 vuplusTV[274:98382] looking for demux module matching "ts": 60 candidates 2016-07-20 21:40:49.754004 vuplusTV[274:98382] Standard set to Auto 2016-07-20 21:40:49.754243 vuplusTV[274:98382] PATCallBack called 2016-07-20 21:40:49.754775 vuplusTV[274:98382] new PAT ts_id=6 version=19 current_next=1 2016-07-20 21:40:49.756302 vuplusTV[274:98382] * number=0 pid=16 2016-07-20 21:40:49.756429 vuplusTV[274:98382] * number=118 pid=97 2016-07-20 21:40:49.756530 vuplusTV[274:98382] temporary receiving program 118 2016-07-20 21:40:49.756865 vuplusTV[274:98382] * number=129 pid=98 2016-07-20 21:40:49.756963 vuplusTV[274:98382] * number=130 pid=99 2016-07-20 21:40:49.757387 vuplusTV[274:98382] * number=131 pid=100 2016-07-20 21:40:49.757481 vuplusTV[274:98382] * number=405 pid=112 2016-07-20 21:40:49.757595 vuplusTV[274:98382] scrambled state changed on pid 32 (0->1) 2016-07-20 21:40:49.757682 vuplusTV[274:98382] pid[32] unknown 2016-07-20 21:40:49.758480 vuplusTV[274:98382] pid[1279] unknown 2016-07-20 21:40:49.758597 vuplusTV[274:98382] pid[1284] unknown 2016-07-20 21:40:49.764168 vuplusTV[274:98382] pid[1283] unknown 2016-07-20 21:40:49.768766 vuplusTV[274:98382] PMTCallBack called for program 131 2016-07-20 21:40:49.769484 vuplusTV[274:98382] new PMT program number=131 version=12 pid_pcr=1279 2016-07-20 21:40:49.769616 vuplusTV[274:98382] * PMT descriptor: CA (0x9) 2016-07-20 21:40:49.770229 vuplusTV[274:98382] : CA System ID 0x9c4 2016-07-20 21:40:49.770425 vuplusTV[274:98382] * PMT descriptor: CA (0x9) 2016-07-20 21:40:49.770534 vuplusTV[274:98382] : CA System ID 0x9af 2016-07-20 21:40:49.770768 vuplusTV[274:98382] * PMT descriptor: CA (0x9) 2016-07-20 21:40:49.771669 vuplusTV[274:98382] : CA System ID 0x98c 2016-07-20 21:40:49.772103 vuplusTV[274:98382] * pid=32 type=0x6 ISO/IEC 13818-1 PES packets containing private data 2016-07-20 21:40:49.772201 vuplusTV[274:98382] - ES descriptor tag 0x52 2016-07-20 21:40:49.772565 vuplusTV[274:98382] - ES descriptor tag 0x56 2016-07-20 21:40:49.773164 vuplusTV[274:98382] * ttxt type=Teletext lan=deu page=100 2016-07-20 21:40:49.773586 vuplusTV[274:98382] * Stream Component Identifier: 10 2016-07-20 21:40:49.773691 vuplusTV[274:98382] => pid 32 has now es fcc=telx 2016-07-20 21:40:49.773818 vuplusTV[274:98382] enabling pcr pid 8191 from program 118 2016-07-20 21:40:49.773949 vuplusTV[274:98382] enabling pcr pid 8191 from program 129 2016-07-20 21:40:49.774058 vuplusTV[274:98382] enabling pcr pid 8191 from program 130 2016-07-20 21:40:49.774223 vuplusTV[274:98382] enabling pid 32 from program 131 2016-07-20 21:40:49.774310 vuplusTV[274:98382] enabling pcr pid 1279 from program 131 2016-07-20 21:40:49.774397 vuplusTV[274:98382] enabling pcr pid 8191 from program 405 2016-07-20 21:40:49.774490 vuplusTV[274:98382] * pid=1279 type=0x1b AVC video stream as defined in ITU-T Rec. H.264 2016-07-20 21:40:49.774805 vuplusTV[274:98382] - ES descriptor tag 0x52 2016-07-20 21:40:49.774910 vuplusTV[274:98382] => pid 1279 has now es fcc=h264 2016-07-20 21:40:49.775275 vuplusTV[274:98382] enabling pcr pid 8191 from program 118 2016-07-20 21:40:49.775378 vuplusTV[274:98382] enabling pcr pid 8191 from program 129 2016-07-20 21:40:49.775465 vuplusTV[274:98382] enabling pcr pid 8191 from program 130 2016-07-20 21:40:49.775551 vuplusTV[274:98382] enabling pid 32 from program 131 2016-07-20 21:40:49.775846 vuplusTV[274:98382] enabling pid 1279 from program 131 2016-07-20 21:40:49.775943 vuplusTV[274:98382] enabling pcr pid 1279 from program 131 2016-07-20 21:40:49.776029 vuplusTV[274:98382] enabling pcr pid 8191 from program 405 2016-07-20 21:40:49.776313 vuplusTV[274:98382] * pid=1283 type=0x6 ISO/IEC 13818-1 PES packets containing private data 2016-07-20 21:40:49.776593 vuplusTV[274:98382] - ES descriptor tag 0x6a 2016-07-20 21:40:49.776745 vuplusTV[274:98382] - ES descriptor tag 0xa 2016-07-20 21:40:49.776836 vuplusTV[274:98382] - ES descriptor tag 0x52 2016-07-20 21:40:49.776935 vuplusTV[274:98382] * Stream Component Identifier: 7 2016-07-20 21:40:49.777151 vuplusTV[274:98382] found language: deu 2016-07-20 21:40:49.777299 vuplusTV[274:98382] => pid 1283 has now es fcc=a52 2016-07-20 21:40:49.778994 vuplusTV[274:98382] enabling pcr pid 8191 from program 118 2016-07-20 21:40:49.779372 vuplusTV[274:98382] enabling pcr pid 8191 from program 129 2016-07-20 21:40:49.779673 vuplusTV[274:98382] enabling pcr pid 8191 from program 130 2016-07-20 21:40:49.781012 vuplusTV[274:98382] enabling pid 32 from program 131 2016-07-20 21:40:49.781253 vuplusTV[274:98382] enabling pid 1279 from program 131 2016-07-20 21:40:49.781356 vuplusTV[274:98382] enabling pid 1283 from program 131 2016-07-20 21:40:49.781598 vuplusTV[274:98382] enabling pcr pid 1279 from program 131 2016-07-20 21:40:49.781693 vuplusTV[274:98382] enabling pcr pid 8191 from program 405 2016-07-20 21:40:49.782027 vuplusTV[274:98382] * pid=1284 type=0x6 ISO/IEC 13818-1 PES packets containing private data 2016-07-20 21:40:49.782389 vuplusTV[274:98382] - ES descriptor tag 0x6a 2016-07-20 21:40:49.782485 vuplusTV[274:98382] - ES descriptor tag 0xa 2016-07-20 21:40:49.782570 vuplusTV[274:98382] - ES descriptor tag 0x52 2016-07-20 21:40:49.782668 vuplusTV[274:98382] * Stream Component Identifier: 8 2016-07-20 21:40:49.782758 vuplusTV[274:98382] found language: eng 2016-07-20 21:40:49.783199 vuplusTV[274:98382] => pid 1284 has now es fcc=a52 2016-07-20 21:40:49.783428 vuplusTV[274:98382] enabling pcr pid 8191 from program 118 2016-07-20 21:40:49.783515 vuplusTV[274:98382] enabling pcr pid 8191 from program 129 2016-07-20 21:40:49.783602 vuplusTV[274:98382] enabling pcr pid 8191 from program 130 2016-07-20 21:40:49.783902 vuplusTV[274:98382] enabling pid 32 from program 131 2016-07-20 21:40:49.784227 vuplusTV[274:98382] enabling pid 1279 from program 131 2016-07-20 21:40:49.784321 vuplusTV[274:98382] enabling pid 1283 from program 131 2016-07-20 21:40:49.784407 vuplusTV[274:98382] enabling pid 1284 from program 131 2016-07-20 21:40:49.784493 vuplusTV[274:98382] enabling pcr pid 1279 from program 131 2016-07-20 21:40:49.784787 vuplusTV[274:98382] enabling pcr pid 8191 from program 405 2016-07-20 21:40:49.785198 vuplusTV[274:98382] * pid=17 listening for SDT 2016-07-20 21:40:49.785305 vuplusTV[274:98382] enabling pcr pid 8191 from program 118 2016-07-20 21:40:49.785391 vuplusTV[274:98382] enabling pcr pid 8191 from program 129 2016-07-20 21:40:49.786406 vuplusTV[274:98382] enabling pcr pid 8191 from program 130 2016-07-20 21:40:49.786524 vuplusTV[274:98382] enabling pid 32 from program 131 2016-07-20 21:40:49.786614 vuplusTV[274:98382] enabling pid 1279 from program 131 2016-07-20 21:40:49.787010 vuplusTV[274:98382] enabling pid 1283 from program 131 2016-07-20 21:40:49.787107 vuplusTV[274:98382] enabling pid 1284 from program 131 2016-07-20 21:40:49.787193 vuplusTV[274:98382] enabling pcr pid 1279 from program 131 2016-07-20 21:40:49.787279 vuplusTV[274:98382] enabling pcr pid 8191 from program 405 2016-07-20 21:40:49.787666 vuplusTV[274:98382] first packet for pid=1279 cc=0x7 2016-07-20 21:40:49.788090 vuplusTV[274:98382] scrambled state changed on pid 32 (0->1) 2016-07-20 21:40:49.789152 vuplusTV[274:98382] using demux module "ts" 2016-07-20 21:40:49.789679 vuplusTV[274:98382] DEMUX_SET_GROUP 0 0x0 2016-07-20 21:40:49.790150 vuplusTV[274:98382] looking for meta reader module matching "any": 1 candidates 2016-07-20 21:40:49.790947 vuplusTV[274:98382] no meta reader modules matched 2016-07-20 21:40:49.791593 vuplusTV[274:98382] `http://root:pass@192.168.42.42:80/file?file=/hdd/movie/SciFi/20160624%200255%20-%20Sky%20Cinema%20HD%20-%20Ant-Man.ts' successfully opened 2016-07-20 21:40:49.792576 vuplusTV[274:98382] Creating delayed ES 2016-07-20 21:40:49.792726 vuplusTV[274:98382] selecting program id=131 2016-07-20 21:40:49.793405 vuplusTV[274:98382] looking for packetizer module matching "any": 24 candidates 2016-07-20 21:40:49.793537 vuplusTV[274:98382] using packetizer module "h264" 2016-07-20 21:40:49.793958 vuplusTV[274:98382] looking for decoder module matching "any": 33 candidates 2016-07-20 21:40:49.795184 vuplusTV[274:98382] option quiet does not exist 2016-07-20 21:40:49.796107 vuplusTV[274:98382] CPU flags: 0x00000068 2016-07-20 21:40:49.808720 vuplusTV[274:98382] allowing 3 thread(s) for decoding 2016-07-20 21:40:49.815753 vuplusTV[274:98382] codec (h264) started 2016-07-20 21:40:49.816041 vuplusTV[274:98382] using frame thread mode with 3 threads 2016-07-20 21:40:49.816153 vuplusTV[274:98382] using decoder module "avcodec" 2016-07-20 21:40:49.816763 vuplusTV[274:98382] Default program is 131 2016-07-20 21:40:49.817754 vuplusTV[274:98382] looking for packetizer module matching "any": 24 candidates 2016-07-20 21:40:49.817996 vuplusTV[274:98382] using packetizer module "a52" 2016-07-20 21:40:49.818175 vuplusTV[274:98382] looking for decoder module matching "any": 33 candidates 2016-07-20 21:40:49.819004 vuplusTV[274:98382] option quiet does not exist 2016-07-20 21:40:49.819174 vuplusTV[274:98382] CPU flags: 0x00000068 2016-07-20 21:40:49.825978 vuplusTV[274:98382] codec (ac3) started 2016-07-20 21:40:49.826166 vuplusTV[274:98382] using decoder module "avcodec" 2016-07-20 21:40:49.827334 vuplusTV[274:98382] enabling pid 32 from program 131 2016-07-20 21:40:49.827586 vuplusTV[274:98382] enabling pid 1279 from program 131 2016-07-20 21:40:49.827682 vuplusTV[274:98382] enabling pid 1283 from program 131 2016-07-20 21:40:49.827769 vuplusTV[274:98382] enabling pid 1284 from program 131 2016-07-20 21:40:49.827856 vuplusTV[274:98382] enabling pcr pid 1279 from program 131 2016-07-20 21:40:49.828407 vuplusTV[274:98382] first packet for pid=1283 cc=0x6 2016-07-20 21:40:49.830349 vuplusTV[274:98382] first packet for pid=1284 cc=0x6 2016-07-20 21:40:49.896756 vuplusTV[274:98382] Buffering 0% 2016-07-20 21:40:49.932724 vuplusTV[274:98382] Buffering 3% 2016-07-20 21:40:49.953902 vuplusTV[274:98382] Buffering 7% 2016-07-20 21:40:49.954278 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:49.992686 vuplusTV[274:98382] Buffering 11% 2016-07-20 21:40:49.992840 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.003708 vuplusTV[274:98382] Buffering 15% 2016-07-20 21:40:50.004043 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.031633 vuplusTV[274:98382] Buffering 19% 2016-07-20 21:40:50.031754 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.040285 vuplusTV[274:98382] Buffering 23% 2016-07-20 21:40:50.041812 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.068410 vuplusTV[274:98382] Buffering 27% 2016-07-20 21:40:50.070395 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.080400 vuplusTV[274:98382] Buffering 31% 2016-07-20 21:40:50.082246 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.111857 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.112012 vuplusTV[274:98382] Buffering 35% 2016-07-20 21:40:50.118472 vuplusTV[274:98382] Buffering 39% 2016-07-20 21:40:50.119783 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.146200 vuplusTV[274:98382] Buffering 43% 2016-07-20 21:40:50.148491 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.156017 vuplusTV[274:98382] Buffering 47% 2016-07-20 21:40:50.157583 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.162443 vuplusTV[274:98382] Buffering 51% 2016-07-20 21:40:50.163528 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.166653 vuplusTV[274:98382] Buffering 55% 2016-07-20 21:40:50.166693 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.168255 vuplusTV[274:98382] Buffering 59% 2016-07-20 21:40:50.168331 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.169556 vuplusTV[274:98382] Buffering 63% 2016-07-20 21:40:50.169565 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.171873 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.171845 vuplusTV[274:98382] Buffering 67% 2016-07-20 21:40:50.172316 vuplusTV[274:98382] Buffering 71% 2016-07-20 21:40:50.173719 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.175618 vuplusTV[274:98382] Buffering 75% 2016-07-20 21:40:50.175826 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.176351 vuplusTV[274:98382] Buffering 79% 2016-07-20 21:40:50.176502 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.178532 vuplusTV[274:98382] Buffering 83% 2016-07-20 21:40:50.178800 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.178951 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.178955 vuplusTV[274:98382] Buffering 87% 2016-07-20 21:40:50.180994 vuplusTV[274:98382] Buffering 91% 2016-07-20 21:40:50.181043 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.181980 vuplusTV[274:98382] Buffering 95% 2016-07-20 21:40:50.182103 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.184208 vuplusTV[274:98382] Buffering 99% 2016-07-20 21:40:50.184211 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.184488 vuplusTV[274:98382] Stream buffering done (1039 ms in 287 ms) 2016-07-20 21:40:50.184689 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.184762 vuplusTV[274:98382] buffer deadlock prevented 2016-07-20 21:40:50.184981 vuplusTV[274:98382] buffer deadlock prevented 2016-07-20 21:40:50.185747 vuplusTV[274:98382] Decoder wait done in 0 ms 2016-07-20 21:40:50.188237 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.188779 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.224017 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.224664 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.300674 vuplusTV[274:98392] A/52 channels:6 samplerate:48000 bitrate:384000 2016-07-20 21:40:50.300875 vuplusTV[274:98392] restarting module due to input format change 2016-07-20 21:40:50.300972 vuplusTV[274:98392] removing module "avcodec" 2016-07-20 21:40:50.301187 vuplusTV[274:98392] ffmpeg codec (ac3) stopped 2016-07-20 21:40:50.301400 vuplusTV[274:98392] looking for decoder module matching "any": 33 candidates 2016-07-20 21:40:50.301861 vuplusTV[274:98392] option quiet does not exist 2016-07-20 21:40:50.301956 vuplusTV[274:98392] CPU flags: 0x00000068 2016-07-20 21:40:50.303200 vuplusTV[274:98392] codec (ac3) started 2016-07-20 21:40:50.303317 vuplusTV[274:98392] using decoder module "avcodec" 2016-07-20 21:40:50.304601 vuplusTV[274:98392] reusing audio output 2016-07-20 21:40:50.305639 vuplusTV[274:98392] VLC is looking for: 'f32l' 48000 Hz 3F2M/LFE frame=1 samples/24 bytes 2016-07-20 21:40:50.468345 vuplusTV[274:98391] waiting for SPS/PPS 2016-07-20 21:40:50.468889 vuplusTV[274:98391] found NAL_SPS (sps_id=0) 2016-07-20 21:40:50.469328 vuplusTV[274:98391] found NAL_PPS (pps_id=0 sps_id=0) 2016-07-20 21:40:50.469443 vuplusTV[274:98391] Seen SEI recovery point, 0 recovery frames 2016-07-20 21:40:50.483792 vuplusTV[274:98391] Recovery from SEI recovery point complete 2016-07-20 21:40:50.484302 vuplusTV[274:98391] restarting module due to input format change 2016-07-20 21:40:50.486559 vuplusTV[274:98391] removing module "avcodec" 2016-07-20 21:40:50.497689 vuplusTV[274:98391] ffmpeg codec (h264) stopped 2016-07-20 21:40:50.498029 vuplusTV[274:98391] looking for decoder module matching "any": 33 candidates 2016-07-20 21:40:50.498928 vuplusTV[274:98391] option quiet does not exist 2016-07-20 21:40:50.499390 vuplusTV[274:98391] CPU flags: 0x00000068 2016-07-20 21:40:50.500325 vuplusTV[274:98391] allowing 3 thread(s) for decoding 2016-07-20 21:40:50.501658 vuplusTV[274:98391] codec (h264) started 2016-07-20 21:40:50.501988 vuplusTV[274:98391] using frame thread mode with 3 threads 2016-07-20 21:40:50.502089 vuplusTV[274:98391] using decoder module "avcodec" 2016-07-20 21:40:50.503958 vuplusTV[274:98401] available software decoder output format 0 (yuv420p) 2016-07-20 21:40:50.510868 vuplusTV[274:98401] looking for text renderer module matching "freetype": 1 candidates 2016-07-20 21:40:50.519537 vuplusTV[274:98392] we set the AU format: [48000.000000][mcpl][9][8][1][8][2][32] 2016-07-20 21:40:50.520483 vuplusTV[274:98392] the actual set AU format is [48000.000000][mcpl][9][8][1][8][2][32] 2016-07-20 21:40:50.627704 vuplusTV[274:98401] using text renderer module "freetype" 2016-07-20 21:40:50.627999 vuplusTV[274:98401] looking for video filter2 module matching "any": 22 candidates 2016-07-20 21:40:50.631443 vuplusTV[274:98401] 32x32 (32x32) chroma: YUVA -> 16x16 (16x16) chroma: RGBA with scaling using Bicubic (good quality) 2016-07-20 21:40:50.631606 vuplusTV[274:98401] using video filter2 module "swscale" 2016-07-20 21:40:50.631754 vuplusTV[274:98401] looking for video filter2 module matching "any": 22 candidates 2016-07-20 21:40:50.631829 vuplusTV[274:98401] YUVP to YUVA converter 2016-07-20 21:40:50.632111 vuplusTV[274:98401] using video filter2 module "yuvp" 2016-07-20 21:40:50.632230 vuplusTV[274:98401] Deinterlacing available 2016-07-20 21:40:50.632663 vuplusTV[274:98401] deinterlace -1, mode blend, is_needed 0 2016-07-20 21:40:50.633006 vuplusTV[274:98401] looking for vout window module matching "any": 0 candidates 2016-07-20 21:40:50.633072 vuplusTV[274:98401] no vout window modules 2016-07-20 21:40:50.633672 vuplusTV[274:98412] Opening vout display wrapper 2016-07-20 21:40:50.633860 vuplusTV[274:98412] looking for vout display module matching "any": 3 candidates 2016-07-20 21:40:50.845104 vuplusTV[274:98392] audio output unit started: 0 2016-07-20 21:40:50.845218 vuplusTV[274:98392] analog AudioUnit output successfully opened 2016-07-20 21:40:50.845290 vuplusTV[274:98392] output 'f32l' 48000 Hz Stereo frame=1 samples/8 bytes 2016-07-20 21:40:50.845377 vuplusTV[274:98392] looking for audio volume module matching "any": 2 candidates 2016-07-20 21:40:50.845424 vuplusTV[274:98392] using audio volume module "float_mixer" 2016-07-20 21:40:50.845469 vuplusTV[274:98392] input 'f32l' 48000 Hz 3F2M/LFE frame=1 samples/24 bytes 2016-07-20 21:40:50.845560 vuplusTV[274:98392] looking for audio filter module matching "scaletempo": 11 candidates 2016-07-20 21:40:50.845609 vuplusTV[274:98392] format: 48000 rate, 6 nch, 4 bps, fl32 2016-07-20 21:40:50.845677 vuplusTV[274:98392] params: 30 stride, 0.200 overlap, 14 search 2016-07-20 21:40:50.845841 vuplusTV[274:98392] 1.000 scale, 1440.000 stride_in, 1440 stride_out, 1152 standing, 288 overlap, 672 search, 2400 queue, fl32 mode 2016-07-20 21:40:50.852733 vuplusTV[274:98392] using audio filter module "scaletempo" 2016-07-20 21:40:50.852802 vuplusTV[274:98392] conversion: 'f32l'->'f32l' 48000 Hz->48000 Hz 3F2M/LFE->3F2M/LFE 2016-07-20 21:40:50.852850 vuplusTV[274:98392] conversion pipeline complete 2016-07-20 21:40:50.852903 vuplusTV[274:98392] conversion: 'f32l'->'f32l' 48000 Hz->48000 Hz 3F2M/LFE->Stereo 2016-07-20 21:40:50.852990 vuplusTV[274:98392] looking for audio converter module matching "any": 7 candidates 2016-07-20 21:40:50.853299 vuplusTV[274:98392] using audio converter module "simple_channel_mixer" 2016-07-20 21:40:50.853349 vuplusTV[274:98392] conversion pipeline complete 2016-07-20 21:40:50.853427 vuplusTV[274:98392] looking for audio resampler module matching "any": 1 candidates 2016-07-20 21:40:50.853473 vuplusTV[274:98392] using audio resampler module "ugly" 2016-07-20 21:40:50.876472 vuplusTV[274:98412] VoutDisplayEvent 'resize' 1920x1080 2016-07-20 21:40:50.877741 vuplusTV[274:98060] VoutDisplayEvent 'resize' 1920x1080 2016-07-20 21:40:50.877764 vuplusTV[274:98412] will use regular OpenGL rendering shader program 1: WARNING: Output of vertex shader 'TexCoord1' not read by fragment shader WARNING: Output of vertex shader 'TexCoord2' not read by fragment shader 2016-07-20 21:40:50.930127 vuplusTV[274:98412] VoutDisplayEvent 'fullscreen' 0 2016-07-20 21:40:50.930225 vuplusTV[274:98412] VoutDisplayEvent 'resize' 1920x1080 2016-07-20 21:40:50.930469 vuplusTV[274:98412] VoutDisplayEvent 'resize' 1920x1080 2016-07-20 21:40:50.930750 vuplusTV[274:98412] using vout display module "ios2" 2016-07-20 21:40:50.931544 vuplusTV[274:98412] original format sz 1920x1090, of (0,0), vsz 1920x1080, 4cc I420, sar 1:1, msk r0x0 g0x0 b0x0 2016-07-20 21:40:50.931943 vuplusTV[274:98412] VoutDisplayEvent 'resize' 1920x1080 2016-07-20 21:40:50.932003 vuplusTV[274:98401] removing module "freetype" 2016-07-20 21:40:50.932359 vuplusTV[274:98401] looking for text renderer module matching "freetype": 1 candidates 2016-07-20 21:40:50.962160 vuplusTV[274:98401] using text renderer module "freetype" 2016-07-20 21:40:51.105407 vuplusTV[274:98412] Detected interlaced video 2016-07-20 21:40:51.105592 vuplusTV[274:98412] deinterlace -1, mode blend, is_needed 1 2016-07-20 21:40:51.105652 vuplusTV[274:98412] Adding 'deinterlace' as static 2016-07-20 21:40:51.105798 vuplusTV[274:98412] looking for video filter2 module matching "deinterlace": 22 candidates 2016-07-20 21:40:51.105870 vuplusTV[274:98412] using blend deinterlace method 2016-07-20 21:40:51.105898 vuplusTV[274:98412] deinterlacing 2016-07-20 21:40:51.105923 vuplusTV[274:98412] using video filter2 module "deinterlace" 2016-07-20 21:40:51.105953 vuplusTV[274:98412] Filter 'deinterlace' (0x102947cf0) appended to chain 2016-07-20 21:40:51.648381 vuplusTV[274:98412] auto hiding mouse cursor 2016-07-20 21:42:15.237110 vuplusTV[274:98382] scrambled state changed on pid 1279 (0->1) 2016-07-20 21:42:15.272316 vuplusTV[274:98382] scrambled state changed on pid 1283 (0->1) 2016-07-20 21:42:15.350405 vuplusTV[274:98382] scrambled state changed on pid 1284 (0->1) 2016-07-20 21:42:39.325357 vuplusTV[274:98060] VoutDisplayEvent 'resize' 1920x1080 2016-07-20 21:43:55.624993 vuplusTV[274:98382] scrambled state changed on pid 1279 (1->0) 2016-07-20 21:43:55.625196 vuplusTV[274:98382] discontinuity received 0x8 instead of 0xb (pid=1279) 2016-07-20 21:43:55.648091 vuplusTV[274:98412] picture is too late to be displayed (missing 98424 ms) 2016-07-20 21:43:55.670878 vuplusTV[274:98382] scrambled state changed on pid 1284 (1->0) 2016-07-20 21:43:55.721306 vuplusTV[274:98412] picture is too late to be displayed (missing 98457 ms) 2016-07-20 21:43:55.743935 vuplusTV[274:98382] scrambled state changed on pid 1283 (1->0) 2016-07-20 21:43:55.744194 vuplusTV[274:98382] discontinuity received 0x8 instead of 0x0 (pid=1283) 2016-07-20 21:43:55.923104 vuplusTV[274:98392] buffer too late (-99512627 us): dropped 2016-07-20 21:43:55.923891 vuplusTV[274:98392] inserting 47930 zeroes 2016-07-20 21:43:57.801961 vuplusTV[274:98412] picture is too late to be displayed (missing 100498 ms) 2016-07-20 21:43:59.767918 vuplusTV[274:98412] picture is too late to be displayed (missing 23 ms) 2016-07-20 21:43:59.768129 vuplusTV[274:98412] picture is too late to be displayed (missing 102384 ms) 2016-07-20 21:44:27.151809 vuplusTV[274:98382] killing decoder fourcc `h264', 43 PES in FIFO 2016-07-20 21:44:27.151944 vuplusTV[274:98382] removing module "avcodec" 2016-07-20 21:44:27.152953 vuplusTV[274:98382] ffmpeg codec (h264) stopped 2016-07-20 21:44:27.153455 vuplusTV[274:98382] saving a free vout 2016-07-20 21:44:27.153756 vuplusTV[274:98382] reusing provided vout 2016-07-20 21:44:27.153879 vuplusTV[274:98382] removing module "h264" 2016-07-20 21:44:27.154125 vuplusTV[274:98412] removing module "deinterlace" 2016-07-20 21:44:27.154188 vuplusTV[274:98412] Filter 0x102947cf0 removed from chain 2016-07-20 21:44:27.154260 vuplusTV[274:98412] Adding 'deinterlace' as static 2016-07-20 21:44:27.154376 vuplusTV[274:98412] looking for video filter2 module matching "deinterlace": 22 candidates 2016-07-20 21:44:27.154443 vuplusTV[274:98412] using blend deinterlace method 2016-07-20 21:44:27.154469 vuplusTV[274:98412] deinterlacing 2016-07-20 21:44:27.154494 vuplusTV[274:98412] using video filter2 module "deinterlace" 2016-07-20 21:44:27.154522 vuplusTV[274:98412] Filter 'deinterlace' (0x1030a30f0) appended to chain 2016-07-20 21:44:27.154563 vuplusTV[274:98382] killing decoder fourcc `a52 ', 0 PES in FIFO 2016-07-20 21:44:27.154590 vuplusTV[274:98382] removing module "avcodec" 2016-07-20 21:44:27.154666 vuplusTV[274:98382] ffmpeg codec (ac3) stopped 2016-07-20 21:44:27.154705 vuplusTV[274:98382] removing module "ugly" 2016-07-20 21:44:27.154755 vuplusTV[274:98382] removing module "scaletempo" 2016-07-20 21:44:27.154824 vuplusTV[274:98382] removing module "simple_channel_mixer" 2016-07-20 21:44:27.168857 vuplusTV[274:98382] removing module "float_mixer" 2016-07-20 21:44:27.168940 vuplusTV[274:98382] keeping audio output 2016-07-20 21:44:27.168979 vuplusTV[274:98382] removing module "a52" 2016-07-20 21:44:27.169035 vuplusTV[274:98382] removing module "ts" 2016-07-20 21:44:27.169899 vuplusTV[274:98382] Program doesn't contain anymore ES 2016-07-20 21:44:27.170770 vuplusTV[274:98382] removing module "record" 2016-07-20 21:44:27.170810 vuplusTV[274:98382] removing module "cache_read" 2016-07-20 21:44:27.171309 vuplusTV[274:98382] removing module "http" 2016-07-20 21:44:27.171987 vuplusTV[274:98774] removing module "audiounit_ios" 2016-07-20 21:44:27.172079 vuplusTV[274:98774] destroying useless vout 2016-07-20 21:44:27.176710 vuplusTV[274:98412] removing module "ios2" 2016-07-20 21:44:27.177800 vuplusTV[274:98412] deleting display 2016-07-20 21:44:27.179493 vuplusTV[274:98412] removing module "deinterlace" 2016-07-20 21:44:27.179554 vuplusTV[274:98412] Filter 0x1030a30f0 removed from chain 2016-07-20 21:44:27.180459 vuplusTV[274:98774] removing module "freetype" 2016-07-20 21:44:27.180898 vuplusTV[274:98774] removing module "yuvp" 2016-07-20 21:44:27.181474 vuplusTV[274:98774] removing module "swscale"

I put some additional blank lines around the interesting part. Looks like the scramble state on 3 PIDs is changing from 0 -> 1 after 86 seconds and then back -> 0 after another 86 seconds.
Anyway I am still puzzled, why VLC on Mac or PC does not have this issue even it is the same file...

PS: sorry for the late reply, I also was busy

[fkuehne]

The nightly builds of VLC for Mac and PC will show the same behavior.

VLC 2.2 does not respect the scramble flag and 3.0 does. Not sure yet if this is a good idea though.

[ssbmaccom]

In general it could make sense to have the option to either ignore or respect the scramble flag to be backwards compatible.
And especially for use within my App - as the scramble flag is changing even nothing is scrambled - could be a bug in the STBs code or the CAM but we should try to get around this.

[InTheWings]

Make sense in which way ?
Trying to figure if the PES header sequence is a false positive and then all the *important* values of that header ? That's the point of ts scrambling flag.

There's currently a workaround if CAT is missing, as scrambling without CAT is nonsensical.
But don't expect that to be fixable if CAT is present.

[ssbmaccom]

Well, it makes sense for most users. They will really complain, when playback fails with new VLC while it plays fine with older versions. And when old version ignored the scramble flag and the new version does not, it also could be done optional - like adding a globally settable flag, if the scramble fields should get ignored.
And yes... let me check about the CAT. for sure the video does not need it, but maybe it still placed in the file. Making this workaround available as option (ignore CAT) would also solve the issue.

I am just afraid, that this might be part of contributed ffMpeg library and not inside the VLC part.

[fkuehne]

No, this parsing is done within VLC and not delegated to libavcodec.