caprica / vlcj

Java framework for the vlc media player
http://www.capricasoftware.co.uk/projects/vlcj
1.13k stars 260 forks source link

Performance issue with hi-res rtsp #481

Closed rukez closed 8 years ago

rukez commented 8 years ago

Hello! I use vlcj for rtsp stream playback, everything is ok with low-res streams, but hi-res stream is missing frames. In pure vlc hi-res stream is showing ok.

Here is my vlcj player code (actually it is taken from docs with some additional args, player is drawing to canvas):

`boolean found = new NativeDiscovery().discover();
        Native.loadLibrary(RuntimeUtil.getLibVlcLibraryName(), LibVlc.class);

        Canvas videoSurface = new Canvas();
        videoSurface.setBackground(Color.black);
        videoSurface.setSize(800, 600);

        List<String> vlcArgs = new ArrayList<String>();
        vlcArgs.add("-vvv");
        vlcArgs.add("--sout-rtp-caching=1000");
        vlcArgs.add("--network-caching=1000");
        vlcArgs.add("--live-caching==1000");
        vlcArgs.add("--rtsp-frame-buffer-size=947483647");
        vlcArgs.add("--no-plugins-cache");
        vlcArgs.add("--avcodec-fast");
        vlcArgs.add("--avcodec-skiploopfilter=4");
        vlcArgs.add("--avcodec-dr");

        MediaPlayerFactory mediaPlayerFactory = new MediaPlayerFactory(vlcArgs);
        EmbeddedMediaPlayer embeddedMediaPlayer = mediaPlayerFactory.newEmbeddedMediaPlayer();
        embeddedMediaPlayer.setVideoSurface(mediaPlayerFactory.newVideoSurface(videoSurface));
        embeddedMediaPlayer.setPlaySubItems(false);

        setLayout(new BorderLayout());
        add(videoSurface, BorderLayout.CENTER);
        embeddedMediaPlayer.playMedia("rtsp://192.168.0.14:554/av0_0");`

And here is vlcj's output:

`[0000000023553dd0] core libvlc debug: VLC media player - 2.2.2 Weatherwax
[0000000023553dd0] core libvlc debug: Copyright � 1996-2016 the VideoLAN team
[0000000023553dd0] core libvlc debug: revision 2.2.2-0-g6259d80
[0000000023553dd0] core libvlc debug: configured with ../extras/package/win32/../../../configure  '--enable-update-check' '--enable-lua' '--enable-faad' '--enable-flac' '--enable-theora' '--enable-twolame' '--enable-quicktime' '--enable-avcodec' '--enable-merge-ffmpeg' '--enable-dca' '--enable-mpc' '--enable-libass' '--enable-x264' '--enable-schroedinger' '--enable-realrtsp' '--enable-live555' '--enable-dvdread' '--enable-shout' '--enable-goom' '--enable-caca' '--disable-sdl' '--enable-qt' '--enable-skins2' '--enable-sse' '--enable-mmx' '--enable-libcddb' '--enable-zvbi' '--disable-telx' '--enable-nls' '--host=x86_64-w64-mingw32' 'host_alias=x86_64-w64-mingw32'
[0000000023553dd0] core libvlc debug: using multimedia timers as clock source
[0000000023553dd0] core libvlc debug:  min period: 1 ms, max period: 1000000 ms
[0000000023553dd0] core libvlc debug: searching plug-in modules
[0000000023553dd0] core libvlc debug: ignoring plugins cache file
[0000000023553dd0] core libvlc debug: recursively browsing `\\?\C:\PROGRA~1\VideoLAN\VLC\plugins'
[0000000023553dd0] core libvlc debug: ignoring plugins cache file
[0000000023553dd0] core libvlc debug: recursively browsing `C:\Program Files\VideoLAN\VLC\plugins'
Qt: Untested Windows version 10.0 detected!
[0000000023553dd0] core libvlc debug: plug-ins loaded: 418 modules
[0000000023553dd0] core libvlc debug: translation test: code is "C"
[0000000023553dd0] core libvlc debug: CPU has capabilities MMX MMXEXT SSE SSE2 SSE3 SSSE3 SSE4.1 FPU 
[00000000234d1710] core generic debug: creating audio output
[000000001da8dae0] core audio output debug: looking for audio output module matching "any": 6 candidates
[000000001da8dae0] directsound audio output debug: found 1 devices
[000000001da8dae0] core audio output debug: using audio output module "directsound"
[00000000234d1710] core generic debug: keeping audio output
[000000001db01130] core input debug: Creating an input for 'rtsp://192.168.0.14:554/av0_0'
[000000001db01130] core input debug: using timeshift granularity of 50 MiB, in path 'C:\Users\orlovsn\AppData\Local\Temp'
[000000001db01130] core input debug: `rtsp://192.168.0.14:554/av0_0' gives access `rtsp' demux `' path `192.168.0.14:554/av0_0'
[000000001db01130] core input debug: specified demux `any'
[000000001db01130] core input debug: creating demux: access='rtsp' demux='any' location='192.168.0.14:554/av0_0' file='\\192.168.0.14:554\av0_0'
[0000000023477910] core demux debug: looking for access_demux module matching "rtsp": 12 candidates
[0000000023477910] live555 demux debug: version 2016.01.12
Opening connection to 192.168.0.14, port 554...
...remote connection opened
Sending request: OPTIONS rtsp://192.168.0.14:554/av0_0 RTSP/1.0

CSeq: 2

User-Agent: LibVLC/2.2.2 (LIVE555 Streaming Media v2016.01.12)

Received 151 new bytes of response data.
Received a complete OPTIONS response:
RTSP/1.0 200 OK

CSeq: 2

Date: Fri, 18 Mar 2016 19:44:20 GMT

Public: OPTIONS, DESCRIBE, SET_PARAMETER,GET_PARAMETER, SETUP, TEARDOWN, PLAY, PAUSE

Sending request: DESCRIBE rtsp://192.168.0.14:554/av0_0 RTSP/1.0

CSeq: 3

User-Agent: LibVLC/2.2.2 (LIVE555 Streaming Media v2016.01.12)

Accept: application/sdp

Received 590 new bytes of response data.
Received a complete DESCRIBE response:
RTSP/1.0 200 OK

CSeq: 3

Server: RTSP-Server/1.0.0

Date: Fri, 18 Mar 2016 19:44:20 GMT

Content-Type: application/sdp

Content-Base: rtsp://192.168.0.14/av0_0

Content-Length: 405

v=0

o=StreamingServer 3433055887 1458330260313613 IN IP4 192.168.0.14

s=av0_0

e=NONE

c=IN IP4 0.0.0.0

t=0 0

m=video 0 RTP/AVP 96

b=AS:70

a=control:trackID=1

a=rtpmap:96 H264/90000

a=fmtp:96 profile-level-id=4d0032;packetization-mode=1;sprop-parameter-sets=Z00AMpWoCgA8abgICAgQ,aO48gA==

a=Media_header:MEDIAINFO=494D4B48010100000400010000000000000000000000000000000000000000000000000000000000;

[0000000023477910] live555 demux debug: RTP subsession 'video/H264'
Sending request: SETUP rtsp://192.168.0.14/av0_0/trackID=1 RTSP/1.0

CSeq: 4

User-Agent: LibVLC/2.2.2 (LIVE555 Streaming Media v2016.01.12)

Transport: RTP/AVP;unicast;client_port=64780-64781

Received 230 new bytes of response data.
Received a complete SETUP response:
RTSP/1.0 200 OK

CSeq: 4

Server: RTSP-Server/1.0.0

Date: Fri, 18 Mar 2016 19:44:20 GMT

Session: 1770499366411301748

Transport: RTP/AVP;unicast;client_port=64780-64781;source=192.168.0.14;server_port=8006-8007;ssrc=50bf1d34

[000000001db01130] core input debug: selecting program id=0
[0000000023477910] live555 demux debug: setup start: 0.000000 stop:0.000000
Sending request: PLAY rtsp://192.168.0.14/av0_0 RTSP/1.0

CSeq: 5

User-Agent: LibVLC/2.2.2 (LIVE555 Streaming Media v2016.01.12)

Session: 1770499366411301748

Range: npt=0.000-

Received 173 new bytes of response data.
Received a complete PLAY response:
RTSP/1.0 200 OK

CSeq: 5

Server: RTSP-Server/1.0.0

Date: Fri, 18 Mar 2016 19:44:20 GMT

Session: 1770499366411301748

RTP-Info: url=rtsp://192.168.0.14/av0_0/trackID=1

[0000000023477910] live555 demux debug: We have a timeout of 60 seconds
[0000000023477910] live555 demux debug: spawned timeout thread
[0000000023477910] live555 demux debug: play start: 0.000000 stop:0.000000
[0000000023477910] core demux debug: using access_demux module "live555"
[000000002335b560] core decoder debug: looking for decoder module matching "any": 43 candidates
[000000002335b560] avcodec decoder debug: CPU flags: 0x010011db
[000000002335b560] avcodec decoder debug: trying to use direct rendering
[000000002335b560] avcodec decoder debug: allowing 4 thread(s) for decoding
[000000002335b560] avcodec decoder warning: threaded frame decoding is not compatible with DXVA2, disabled
[000000002335b560] avcodec decoder debug: avcodec codec (H264 - MPEG-4 AVC (part 10)) started
[000000002335b560] avcodec decoder debug: using slice thread mode with 4 threads
[000000002335b560] core decoder debug: using decoder module "avcodec"
[00000000233f1120] core packetizer debug: looking for packetizer module matching "any": 23 candidates
[00000000233f1120] packetizer_h264 packetizer debug: found NAL_SPS (sps_id=0)
[00000000233f1120] packetizer_h264 packetizer debug: found NAL_PPS (pps_id=0 sps_id=0)
[00000000233f1120] core packetizer debug: using packetizer module "packetizer_h264"
[000000001db02d00] core demux meta debug: looking for meta reader module matching "any": 2 candidates
[000000001db02d00] lua demux meta debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\reader
[000000001db02d00] lua demux meta debug: Trying Lua scripts in \\?\C:\PROGRA~1\VideoLAN\VLC\lua\meta\reader
[000000001db02d00] lua demux meta debug: Trying Lua playlist script \\?\C:\PROGRA~1\VideoLAN\VLC\lua\meta\reader\filename.luac
[000000001db02d00] core demux meta debug: no meta reader modules matched
[000000001db01130] core input debug: `rtsp://192.168.0.14:554/av0_0' successfully opened
Sending request: GET_PARAMETER rtsp://192.168.0.14/av0_0 RTSP/1.0

CSeq: 6

User-Agent: LibVLC/2.2.2 (LIVE555 Streaming Media v2016.01.12)

Session: 1770499366411301748

[000000001db01130] core input debug: Buffering 0%
[000000001db01130] core input debug: Buffering 0%
[000000001db01130] core input debug: Buffering 0%
Received 95 new bytes of response data.
Received a complete GET_PARAMETER response:
RTSP/1.0 200 OK

CSeq: 6

Date: Fri, 18 Mar 2016 19:44:20 GMT

Session: 1770499366411301748

[000000001db01130] core input debug: Buffering 0%
[000000001db01130] core input debug: Buffering 4%
[000000002335b560] [000000001db01130] avcodec decoder debug: core input debug: available hardware decoder output format 61 (dxva2_vld)Buffering 8%

[000000002335b560] avcodec decoder debug: available software decoder output format 12 (yuvj420p)
[00000000233ff340] core generic debug: looking for hw decoder module matching "any": 1 candidates
[00000000233ff340] core generic debug: no hw decoder modules matched
[000000001db01130] core input debug: Buffering 12%
[00000000235efff0] core spu text debug: looking for text renderer module matching "any": 2 candidates
[000000001db01130] core input debug: Buffering 16%
[00000000235efff0] freetype spu text debug: Using Arial as font from file C:\Windows\Fonts\arial.ttf
[00000000235efff0] freetype spu text debug: Using Courier New as mono-font from file C:\Windows\Fonts\cour.ttf
[000000001db01130] core input debug: Buffering 20%
[00000000235efff0] freetype spu text debug: using fontsize: 2
[00000000235efff0] core spu text debug: using text renderer module "freetype"
[0000000023449c60] core scale debug: looking for video filter2 module matching "any": 58 candidates
[000000001db01130] core input debug: Buffering 24%
[0000000023449c60] swscale scale debug: 32x32 (32x32) chroma: YUVA -> 16x16 (16x16) chroma: RGBA with scaling using Bicubic (good quality)
[0000000023449c60] core scale debug: using video filter2 module "swscale"
[00000000237d6c40] core scale debug: looking for video filter2 module matching "any": 58 candidates
[000000001db01130] core input debug: Buffering 28%
[000000001db01130] core input debug: Buffering 32%
[000000001db01130] core input debug: Buffering 36%
[00000000237d6c40] yuvp scale debug: YUVP to YUVA converter
[00000000237d6c40] core scale debug: using video filter2 module "yuvp"
[000000001db01130] core input debug: Buffering 40%
[000000001db5e470] core video output debug: Deinterlacing available
[000000001db5e470] core video output debug: deinterlace 0, mode blend, is_needed 0
[000000001db01130] core input debug: Buffering 44%
[000000001db5e470] core video output debug: Opening vout display wrapper
[00000000237edfb0] core vout display debug: looking for vout display module matching "any": 11 candidates
[000000001db01130] core input debug: Buffering 48%
[000000001db01130] core input debug: Buffering 52%
[000000001db01130] core input debug: Buffering 56%
[000000001db01130] core input debug: Buffering 60%
[000000001db01130] core input debug: Buffering 64%
[000000001db01130] core input debug: Buffering 64%
[000000001db01130] core input debug: Buffering 64%
[000000001db01130] core input debug: Buffering 64%
[000000001db01130] core input debug: Buffering 68%
[00000000237edfb0] direct3d vout display warning: cannot load Direct3D Shader Library; HLSL pixel shading will be disabled.
[00000000237edfb0] direct3d vout display debug: creating Vout EventThread
[00000000237edfb0] direct3d vout display debug: Win32VoutCreateWindow
[00000000233ff430] core window debug: looking for vout window hwnd module matching "embed-hwnd,any": 3 candidates
[00000000233ff430] core window debug: using vout window hwnd module "drawable"
[00000000237edfb0] direct3d vout display debug: created video sub-window
[00000000237edfb0] direct3d vout display debug: Vout EventThread running
[00000000237edfb0] direct3d vout display debug: disabling screen saver
[00000000237edfb0] direct3d vout display debug: Direct3d Device: NVIDIA GeForce 6600 GT  4318 320 162
[000000001db01130] core input debug: Buffering 72%
[000000001db01130] core input debug: Buffering 76%
[00000000237edfb0] core vout display debug: VoutDisplayEvent 'resize' 2576x1959 window
[00000000237edfb0] direct3d vout display warning: trying surface pixel format: YV12
[00000000237edfb0] direct3d vout display debug: selected surface pixel format is YV12
[00000000237edfb0] direct3d vout display debug: Using D3DTEXF_LINEAR for minification
[00000000237edfb0] direct3d vout display debug: Using D3DTEXF_LINEAR for magnification
[00000000237edfb0] direct3d vout display debug: Direct3D scene created successfully
[00000000237edfb0] direct3d vout display warning: Direct3D shaders initialization failed !
[00000000237edfb0] direct3d vout display debug: Direct3D device adapter successfully initialized
[00000000237edfb0] core vout display debug: using vout display module "direct3d"
[000000001db5e470] core video output debug: original format sz 2560x1922, of (0,0), vsz 2560x1920, 4cc J420, sar 1:1, msk r0x0 g0x0 b0x0
[00000000235efff0] core spu text debug: removing module "freetype"
[00000000235efff0] core spu text debug: looking for text renderer module matching "any": 2 candidates
[00000000237edfb0] core vout display debug: VoutDisplayEvent 'resize' 788x569 window
[00000000235efff0] freetype spu text debug: Using Arial as font from file C:\Windows\Fonts\arial.ttf
[00000000235efff0] freetype spu text debug: Using Courier New as mono-font from file C:\Windows\Fonts\cour.ttf
[00000000235efff0] freetype spu text debug: using fontsize: 2
[00000000235efff0] core spu text debug: using text renderer module "freetype"
[00000000237edfb0] core vout display error: Failed to set on top
[000000002335b560] avcodec decoder warning: plane 0 not aligned
[000000002335b560] avcodec decoder warning: disabling direct rendering
[000000001db01130] core input debug: Buffering 80%
[000000001db01130] core input debug: Buffering 84%
[000000002335b560] core decoder debug: End of video preroll
[000000002335b560] core decoder debug: Received first picture
[000000001db01130] core input debug: Buffering 88%
[000000001db01130] core input debug: Buffering 92%
[000000001db01130] core input debug: Buffering 96%
[000000001db01130] core input debug: Stream buffering done (1001 ms in 330 ms)
[000000001db01130] core input debug: Decoder wait done in 0 ms
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 24 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 34 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 52 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 33 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 40 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 61 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 43 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 51 ms)
[00000000237edfb0] core vout display debug: auto hiding mouse cursor
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 75 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 96 ms)
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000001db5e470] core video output debug: picture might be displayed late (missing 3 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 68 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 49 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 61 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 94 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 116 ms)
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 23 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 97 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 174 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 197 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 178 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 166 ms)
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000001db5e470] core video output debug: picture might be displayed late (missing 9 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 23 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 69 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 91 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 121 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 134 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 115 ms)
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000002335b560] avcodec decoder warning: More than 4 late frames, dropping frame
[000000001db5e470] core video output debug: picture might be displayed late (missing 10 ms)
[000000001db5e470] core video output warning: picture is too late to be displayed (missing 85 ms)`

**So tons of frames are "late to be displayed". As you can see avccodec performance options are allready enabled. --no-skip-frames don't help - vlc just dropping frames then, --no-drop-late-frames don't help also. I've tried setting huge network cache option but only --live-caching increasing change something - instead of multiple drops log contains also multiple "core video output debug: picture might be displayed late". Leaving rtsp cache in default low value don't help also. After some time (about a minute) playback may become (not allways) more stable, can be played without drops for 30-60 seconds, than some more drops, than stable again and so on. Also, after some time, multi-drops commonly starts with zero time delay (picture might be displayed late (missing 0 ms))

When i open same rtsp in pure VLC, playback is ok - only first frame is rendered buggy (it's ok because in vlcj i set huge frame buffer, vlc is launched without any options, just -vvv) and second frame is dropped with "picture is too late to be displayed". Next frames are rendered perfectly without any issues for hours of playback. Here is VLC connection log:**

`
core debug: VLC media player - 2.2.2 Weatherwax
core debug: Copyright © 1996-2016 the VideoLAN team
core debug: revision 2.2.2-0-g6259d80
core debug: configured with ../extras/package/win32/../../../configure '--enable-update-check' '--enable-lua' '--enable-faad' '--enable-flac' '--enable-theora' '--enable-twolame' '--enable-quicktime' '--enable-avcodec' '--enable-merge-ffmpeg' '--enable-dca' '--enable-mpc' '--enable-libass' '--enable-x264' '--enable-schroedinger' '--enable-realrtsp' '--enable-live555' '--enable-dvdread' '--enable-shout' '--enable-goom' '--enable-caca' '--disable-sdl' '--enable-qt' '--enable-skins2' '--enable-sse' '--enable-mmx' '--enable-libcddb' '--enable-zvbi' '--disable-telx' '--enable-nls' '--host=x86_64-w64-mingw32' 'host_alias=x86_64-w64-mingw32'
core debug: adding item `rtsp://192.168.0.14:554' ( rtsp://admin:admin@192.168.0.14:554 )
core debug: processing request item: rtsp://192.168.0.14:554, node: null, skip: 0
core debug: rebuilding array of current - root Плейлист
core debug: rebuild done - 1 items, index 0
core debug: starting playback of the new playlist item
core debug: resyncing on rtsp://192.168.0.14:554
core debug: meta ok for (null), need to fetch art
core debug: rtsp://192.168.0.14:554 is at 0
core debug: creating new input thread
core debug: Creating an input for 'rtsp://192.168.0.14:554'
core debug: looking for meta fetcher module matching "any": 1 candidates
core debug: requesting art for rtsp://192.168.0.14:554
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\fetcher
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\fetcher
core debug: looking for meta fetcher module matching "any": 1 candidates
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac
core debug: using timeshift granularity of 50 MiB, in path 'C:\Users\orlovsn\AppData\Local\Temp'
core debug: `rtsp://admin:admin@192.168.0.14:554' gives access `rtsp' demux `' path `admin:admin@192.168.0.14:554'
core debug: specified demux `any'
core debug: creating demux: access='rtsp' demux='any' location='admin:admin@192.168.0.14:554' file='\\admin:admin@192.168.0.14:554'
core debug: looking for access_demux module matching "rtsp": 12 candidates
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\fetcher
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\fetcher
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac
core debug: no meta fetcher modules matched
core debug: searching art for rtsp://192.168.0.14:554
core debug: looking for art finder module matching "any": 2 candidates
live555 debug: version 2016.01.12
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac
core debug: no meta fetcher modules matched
core debug: searching art for rtsp://192.168.0.14:554
core debug: looking for art finder module matching "any": 2 candidates
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\art
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\art
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\art
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\art
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\01_googleimage.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\01_googleimage.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\01_googleimage.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\01_googleimage.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\03_lastfm.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\03_lastfm.luac
core debug: no art finder modules matched
core debug: looking for meta fetcher module matching "any": 1 candidates
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\03_lastfm.luac
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\fetcher
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\fetcher
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac
lua debug: skipping script (unmatched scope) C:\Program Files\VideoLAN\VLC\lua\meta\art\03_lastfm.luac
core debug: no art finder modules matched
core debug: looking for meta fetcher module matching "any": 1 candidates
core debug: using meta fetcher module "lua"
core debug: removing module "lua"
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\fetcher
core debug: searching art for rtsp://192.168.0.14:554
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\fetcher
core debug: looking for art finder module matching "any": 2 candidates
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\fetcher\tvrage.luac
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\art
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\art
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac
core debug: using meta fetcher module "lua"
core debug: removing module "lua"
core debug: searching art for rtsp://192.168.0.14:554
qt4 debug: IM: Setting an input
core debug: looking for art finder module matching "any": 2 candidates
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\01_googleimage.luac
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\art
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\art
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\00_musicbrainz.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\01_googleimage.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\03_lastfm.luac
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\02_frenchtv.luac
core debug: no art finder modules matched
core debug: art not found for rtsp://192.168.0.14:554
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\art\03_lastfm.luac
core debug: no art finder modules matched
core debug: art not found for rtsp://192.168.0.14:554
live555 debug: RTP subsession 'video/H264'
core debug: selecting program id=0
live555 debug: setup start: 0.000000 stop:0.000000
live555 debug: We have a timeout of 60 seconds
live555 debug: spawned timeout thread
live555 debug: play start: 0.000000 stop:0.000000
core debug: using access_demux module "live555"
core debug: looking for decoder module matching "any": 43 candidates
avcodec debug: CPU flags: 0x010011db
avcodec debug: trying to use direct rendering
avcodec debug: allowing 4 thread(s) for decoding
avcodec debug: avcodec codec (H264 - MPEG-4 AVC (part 10)) started
avcodec debug: using frame thread mode with 4 threads
core debug: using decoder module "avcodec"
core debug: looking for packetizer module matching "any": 23 candidates
packetizer_h264 debug: found NAL_SPS (sps_id=0)
packetizer_h264 debug: found NAL_PPS (pps_id=0 sps_id=0)
core debug: using packetizer module "packetizer_h264"
core debug: looking for meta reader module matching "any": 2 candidates
lua debug: Trying Lua scripts in C:\Users\orlovsn\AppData\Roaming\vlc\lua\meta\reader
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\reader
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\reader\filename.luac
core debug: no meta reader modules matched
core debug: `rtsp://admin:admin@192.168.0.14:554' successfully opened
core debug: Buffering 0%
core debug: Buffering 0%
core debug: Buffering 0%
live555 debug: lost 207192 bytes
live555 debug: increasing buffer size to 200000
core debug: Buffering 0%
core debug: Stream buffering done (1000 ms in 19 ms)
core debug: Decoder wait done in 0 ms
avcodec debug: available hardware decoder output format 61 (dxva2_vld)
avcodec debug: available software decoder output format 12 (yuvj420p)
core debug: looking for hw decoder module matching "none": 1 candidates
core debug: no hw decoder modules matched
live555 debug: lost 87716 bytes
live555 debug: increasing buffer size to 400000
core debug: looking for text renderer module matching "any": 2 candidates
freetype debug: Using Arial as font from file C:\Windows\Fonts\arial.ttf
freetype debug: Using Courier New as mono-font from file C:\Windows\Fonts\cour.ttf
freetype debug: using fontsize: 2
core debug: using text renderer module "freetype"
core debug: looking for video filter2 module matching "any": 58 candidates
swscale debug: 32x32 (32x32) chroma: YUVA -> 16x16 (16x16) chroma: RGBA with scaling using Bicubic (good quality)
core debug: using video filter2 module "swscale"
core debug: looking for video filter2 module matching "any": 58 candidates
yuvp debug: YUVP to YUVA converter
core debug: using video filter2 module "yuvp"
core debug: Deinterlacing available
core debug: deinterlace 0, mode blend, is_needed 0
core debug: Opening vout display wrapper
core debug: looking for vout display module matching "any": 11 candidates
direct3d warning: cannot load Direct3D Shader Library; HLSL pixel shading will be disabled.
direct3d debug: creating Vout EventThread
direct3d debug: Win32VoutCreateWindow
core debug: looking for vout window hwnd module matching "qt4,any": 3 candidates
qt4 debug: requesting video window...
qt4 debug: Video was requested 0, 0
core debug: using vout window hwnd module "qt4"
direct3d debug: created video sub-window
direct3d debug: Vout EventThread running
direct3d debug: disabling screen saver
direct3d debug: Direct3d Device: NVIDIA GeForce 6600 GT 4318 320 162
core debug: VoutDisplayEvent 'resize' 2576x1959 window
direct3d warning: trying surface pixel format: YV12
direct3d debug: selected surface pixel format is YV12
direct3d debug: Using D3DTEXF_LINEAR for minification
direct3d debug: Using D3DTEXF_LINEAR for magnification
direct3d debug: Direct3D scene created successfully
direct3d warning: Direct3D shaders initialization failed !
direct3d debug: Direct3D device adapter successfully initialized
core debug: using vout display module "direct3d"
core debug: original format sz 2560x1922, of (0,0), vsz 2560x1920, 4cc J420, sar 1:1, msk r0x0 g0x0 b0x0
core debug: removing module "freetype"
core debug: looking for text renderer module matching "any": 2 candidates
core debug: VoutDisplayEvent 'resize' 1920x944 window
freetype debug: Using Arial as font from file C:\Windows\Fonts\arial.ttf
freetype debug: Using Courier New as mono-font from file C:\Windows\Fonts\cour.ttf
freetype debug: using fontsize: 2
core debug: using text renderer module "freetype"
avcodec warning: plane 0 not aligned
avcodec warning: disabling direct rendering
core debug: End of video preroll
core warning: picture is too late to be displayed (missing 178 ms)
core warning: picture is too late to be displayed (missing 145 ms)
core warning: picture is too late to be displayed (missing 105 ms)
core warning: picture is too late to be displayed (missing 65 ms)
core warning: picture is too late to be displayed (missing 25 ms)
core debug: picture might be displayed late (missing 15 ms)
core debug: picture might be displayed late (missing 4 ms)
core debug: auto hiding mouse cursor
core warning: picture is too late to be displayed (missing 39 ms)
core warning: picture is too late to be displayed (missing 21 ms)
core debug: auto hiding mouse cursor
core debug: auto hiding mouse cursor
live555 debug: lost 113752 bytes
live555 debug: increasing buffer size to 800000`

Test system is old 8 core xeon with nvidia 6600gt While playback none of cores are loaded to maximum (7 are almost idle, 1 is loaded to ~80%)

Maybe i need to set some kind of caching or time-related options, that are used by VLC by default, but are lost when using VLC through VLCJ?

I have tried --clock-jitter=2147483647, huge file, network and rtsp caches, disabling of network clock sync and so on.

rukez commented 8 years ago

Oups, looks like i figured out: When i set --rtsp-frame-buffer-size option below 200000 value, value seems to be dropped to default (200000). And when this value is too high (947483647 in my example above) frame drops appear until this buffer is full, so setting 500000 seems to eleminate difference in VLCJ and VLC behaviour. Do i need to specify buffer length relatively to stream resolution (frame size) or it can be auto-changed on-the-fly? If i have to take care of it, how can i determine stream resolution via VLCJ without actually getting video data (rtp stream), to make one rtsp call for info, than setting buffers size and then connecting to rtsp for video data?

caprica commented 8 years ago

I have no idea really. Those switches are not supported by LibVLC. vlcj does nothing with them apart from pass them to VLC.

rukez commented 8 years ago

I figured out how --rtsp-frame-buffer-size buffer works - default is 200k (and looks like no way to set it lower), on each frame that is larger than buffer size, live555 increase buffer automatically. Seems like there is no way to reasonable-fast check stream resolution before playback, so fastest way is to connect with hidden video layer, get resolution of received frame, if it's possible size is lower than default buffer - show video layer, if possible size is bigger - stay hidden for one frame, than repeat check taking in mind auto-increased buffer.

Trouble is that after some time of testing (no code was changed) problem repeated and --rtsp-frame-buffer-size fix stopped working. I've tried DirectMediaPlayer instead of embedded one ... i still have ton's of "picture is too late to be displayed" warnings in log, but playback is very nice - no picture stall, no skips, looks like even no frame drops. CPU usage is almost the same - 5mpx stream rendering to 800x600 panel takes about 70-80% of one core (this is most strange - last time i tried it year ago difference was much higher) - i'll try to change test PC - maybe old 6600gt simply fails to renderer properly.

caprica commented 8 years ago

It's not clear to me if there's still a problem or not...

utsavdusad commented 7 years ago

I am also facing the similar issue. Has anyone fixed it?