VLC 2.2.8 on RPi - no or choppy playback of some udp streams
Posted: 05 Apr 2018 11:12
Hi
We use 2.2.8 on RPi 3 to show udp and rtp IPTV usually without issues.
We now have udp streams that are locally generated from jpg stills (slideshows) and audio, encoded as H.264 video.
These streams can be perfectly received and played on a PC - no errors even on level 2.
However, on a RPi there sometimes is no picture at all, sometimes a jaggy one and chopped audio. There are uncountable errors - I add the log until the first few errors that repeat endless from there on below.
What could be the cause for this?
Thanks
McL
core debug: processing request item: udp://239.192.4.1:1234, node: Wiedergabeliste, skip: 0
core debug: resyncing on udp://239.192.4.1:1234
core debug: udp://239.192.4.1:1234 is at 0
core debug: starting playback of the new playlist item
core debug: resyncing on udp://239.192.4.1:1234
core debug: udp://239.192.4.1:1234 is at 0
core debug: creating new input thread
core debug: Creating an input for 'udp://239.192.4.1:1234'
core debug: requesting art for udp://239.192.4.1:1234
core debug: using timeshift granularity of 50 MiB, in path '/tmp'
core debug: `udp://@239.192.4.1:1234' gives access `udp' demux `' path `@239.192.4.1:1234'
core debug: specified demux `any'
core debug: creating demux: access='udp' demux='any' location='@239.192.4.1:1234' file='(null)'
core debug: looking for access_demux module matching "udp": 21 candidates
core debug: no access_demux modules matched
core debug: creating access 'udp' location='@239.192.4.1:1234', path='(null)'
core debug: looking for access module matching "udp": 23 candidates
udp debug: opening server=:0 local=239.192.4.1:1234
core debug: net: opening 239.192.4.1 datagram port 1234
core debug: looking for meta fetcher module matching "any": 1 candidates
core debug: using access module "udp"
core debug: Using block method for AStream*
core debug: starting pre-buffering
core debug: received first data after 9 ms
core debug: prebuffering done 1316 bytes in 0s - 133 KiB/s
core debug: looking for stream_filter module matching "any": 9 candidates
core debug: no stream_filter modules matched
core debug: looking for stream_filter module matching "record": 9 candidates
core debug: using stream_filter module "record"
core debug: creating demux: access='udp' demux='any' location='@239.192.4.1:1234' file='(null)'
core debug: looking for demux module matching "any": 65 candidates
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/fetcher
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/fetcher
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/fetcher/tvrage.luac
core warning: cannot load module `/usr/lib/vlc/plugins/demux/libmkv_plugin.so' (/usr/lib/vlc/plugins/demux/libmkv_plugin.so: undefined symbol: _ZNK7libebml10EbmlStringcvRKSsEv)
core error: corrupt module: /usr/lib/vlc/plugins/demux/libmkv_plugin.so
mod debug: MOD validation failed (ext=)
ts debug: Force Seek Per Percent: PCR's not found,
ts debug: pid[257] unknown
ts debug: pid[259] unknown
ts debug: pid[258] unknown
ts debug: PATCallBack called
ts debug: new PAT ts_id=1 version=5 current_next=1
ts debug: * number=0 pid=16
ts debug: * number=257 pid=256
ts debug: PMTCallBack called
ts debug: new PMT program number=257 version=5 pid_pcr=259
ts debug: * es pid=257 type=27 fcc=h264
core debug: selecting program id=257
ts debug: * es pid=258 type=3 fcc=mpga
core debug: using demux module "ts"
core debug: looking for decoder module matching "any": 46 candidates
omxil debug: fmt in:h264, out:
omxil debug: component OMX.broadcom.audio_capture
omxil debug: component OMX.broadcom.audio_decode
omxil debug: component OMX.broadcom.audio_encode
omxil debug: component OMX.broadcom.audio_render
omxil debug: component OMX.broadcom.audio_mixer
omxil debug: component OMX.broadcom.audio_splitter
omxil debug: component OMX.broadcom.audio_processor
omxil debug: component OMX.broadcom.camera
omxil debug: component OMX.broadcom.clock
omxil debug: component OMX.broadcom.coverage
omxil debug: component OMX.broadcom.egl_render
omxil debug: component OMX.broadcom.image_fx
omxil debug: component OMX.broadcom.image_decode
omxil debug: component OMX.broadcom.image_encode
omxil debug: component OMX.broadcom.image_read
omxil debug: component OMX.broadcom.image_write
omxil debug: component OMX.broadcom.read_media
omxil debug: component OMX.broadcom.resize
omxil debug: component OMX.broadcom.source
omxil debug: component OMX.broadcom.text_scheduler
omxil debug: component OMX.broadcom.transition
omxil debug: component OMX.broadcom.video_decode
omxil debug: component OMX.broadcom.video_encode
omxil debug: component OMX.broadcom.video_render
omxil debug: component OMX.broadcom.video_scheduler
omxil debug: component OMX.broadcom.video_splitter
omxil debug: component OMX.broadcom.visualisation
omxil debug: component OMX.broadcom.write_media
omxil debug: component OMX.broadcom.write_still
omxil debug: found 1 matching components for role video_decoder.avc
omxil debug: - OMX.broadcom.video_decode
omxil debug: loaded component OMX.broadcom.video_decode
omxil debug: found 0 audio ports
omxil debug: found 0 image ports
omxil debug: found 2 video ports
omxil debug: -> input 130 (0 streams) (20:1:81920 buffers) (0,16) enabled
omxil debug: -> video MPEG-4 Video 0x0@0.00 (4,0) (0,0) (0,0,0,0)
omxil debug: -> output 131 (0 streams) (1:1:115200 buffers) (0,16) enabled
omxil debug: -> video Planar 4:2:0 YUV 320x240@0.00 (0,20) (320,240) (0,0,320,240)
omxil debug: Enabled aspect ratio notifications
omxil debug: StartWithValidFrame disabled.
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateIdle)
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateExecuting)
omxil debug: -> input 130 (0 streams) (20:1:81920 buffers) (0,16) enabled
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/fetcher/tvrage.luac
omxil debug: -> video H264 - MPEG-4 AVC (part 10) 0x0@0.00 (7,0) (0,0) (0,0,0,0)
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/fetcher
core debug: no meta fetcher modules matched
core debug: searching art for udp://239.192.4.1:1234
omxil debug: -> output 131 (0 streams) (1:1:0 buffers) (0,16) enabled
omxil debug: -> video Planar 4:2:0 YUV 0x0@0.00 (0,20) (0,240) (0,0,0,0)
core debug: using decoder module "omxil"
core debug: looking for art finder module matching "any": 2 candidates
core debug: looking for packetizer module matching "any": 23 candidates
core debug: using packetizer module "packetizer_h264"
qt4 debug: IM: Setting an input
core debug: looking for decoder module matching "any": 46 candidates
core debug: using decoder module "mpeg_audio"
ts debug: DEMUX_SET_GROUP 0 (nil)
core debug: looking for meta reader module matching "any": 2 candidates
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/art
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/art
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/00_musicbrainz.luac
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/reader
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/reader
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/reader/filename.luac
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/00_musicbrainz.luac
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/01_googleimage.luac
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/reader
core debug: no meta reader modules matched
core debug: `udp://@239.192.4.1:1234' successfully opened
ts warning: first packet for pid=257 cc=0xf
ts debug: pid[1] unknown
ts warning: discontinuity received 0xb instead of 0x6 (pid=257)
ts warning: first packet for pid=258 cc=0x9
core debug: Buffering 0%
packetizer_h264 warning: waiting for SPS/PPS
core debug: Buffering 2%
mpeg_audio debug: MPGA channels:2 samplerate:48000 bitrate:256
core debug: reusing audio output
core debug: Buffering 5%
packetizer_h264 warning: waiting for SPS/PPS
alsa debug: using ALSA device: default
alsa debug: Hardware PCM card 1 'USB AUDIO CODEC' device 0 subdevice 0
alsa debug: device name : USB Audio
alsa debug: device ID : USB Audio
alsa debug: subdevice name: subdevice #0
alsa debug: initial hardware setup: ACCESS: MMAP_INTERLEAVED RW_INTERLEAVED FORMAT: S8 S16_LE SUBFORMAT: STD SAMPLE_BITS: [8 16] FRAME_BITS: [8 32] CHANNELS: [1 2] RATE: [32000 48000] PERIOD_TIME: [1000 16384000] PERIOD_SIZE: [32 524288] PERIOD_BYTES: [64 524288] PERIODS: [2 1024] BUFFER_TIME: (1333 32768000] BUFFER_SIZE: [64 1048576] BUFFER_BYTES: [64 1048576] TICK_TIME: ALL
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
alsa debug: using channels map 0, type 1, 2 channel(s)
alsa debug: final HW setup: ACCESS: RW_INTERLEAVED FORMAT: S16_LE SUBFORMAT: STD SAMPLE_BITS: 16 FRAME_BITS: 32 CHANNELS: 2 RATE: 48000 PERIOD_TIME: 40000 PERIOD_SIZE: 1920 PERIOD_BYTES: 7680 PERIODS: 75 BUFFER_TIME: 3000000 BUFFER_SIZE: 144000 BUFFER_BYTES: 576000 TICK_TIME: 0
alsa debug: initial software parameters: tstamp_mode: NONE tstamp_type: MONOTONIC period_step: 1 avail_min: 1920 start_threshold: 1 stop_threshold: 144000 silence_threshold: 0 silence_size: 0 boundary: 1179648000
alsa debug: final software parameters: tstamp_mode: NONE tstamp_type: MONOTONIC period_step: 1 avail_min: 1920 start_threshold: 1 stop_threshold: 144000 silence_threshold: 0 silence_size: 0 boundary: 1179648000
core debug: output 's16l' 48000 Hz Stereo frame=1 samples/4 bytes
core debug: looking for audio volume module matching "any": 2 candidates
core debug: using audio volume module "integer_mixer"
core debug: input 'mpga' 48000 Hz Stereo frame=1152 samples/1161 bytes
core debug: looking for audio filter module matching "scaletempo": 14 candidates
scaletempo debug: format: 48000 rate, 2 nch, 4 bps, fl32
scaletempo debug: params: 30 stride, 0.200 overlap, 14 search
scaletempo debug: 1.000 scale, 1440.000 stride_in, 1440 stride_out, 1152 standing, 288 overlap, 672 search, 2400 queue, fl32 mode
core debug: using audio filter module "scaletempo"
core debug: conversion: 'mpga'->'f32l' 48000 Hz->48000 Hz Stereo->Stereo
core debug: looking for audio converter module matching "any": 12 candidates
core debug: no audio converter modules matched
core debug: Buffering 8%
core debug: looking for audio converter module matching "any": 12 candidates
mpgatofixed32 debug: mpga->f32l, bits per sample: 32
core debug: using audio converter module "mpgatofixed32"
core debug: conversion pipeline complete
core debug: conversion: 'f32l'->'s16l' 48000 Hz->48000 Hz Stereo->Stereo
core debug: looking for audio converter module matching "any": 12 candidates
audio_format debug: f32l->s16l, bits per sample: 0->16
core debug: using audio converter module "audio_format"
core debug: conversion pipeline complete
core debug: looking for audio resampler module matching "any": 3 candidates
core debug: using audio resampler module "ugly_resampler"
core debug: End of audio preroll
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/01_googleimage.luac
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/02_frenchtv.luac
packetizer_h264 warning: waiting for SPS/PPS
core debug: Buffering 11%
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/02_frenchtv.luac
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/03_lastfm.luac
packetizer_h264 warning: waiting for SPS/PPS
core debug: Buffering 14%
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/03_lastfm.luac
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/art
core debug: no art finder modules matched
core debug: looking for meta fetcher module matching "any": 1 candidates
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/fetcher
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/fetcher
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/fetcher/tvrage.luac
core debug: Buffering 17%
core debug: using meta fetcher module "lua"
core debug: removing module "lua"
core debug: searching art for udp://239.192.4.1:1234
core debug: looking for art finder module matching "any": 2 candidates
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/art
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/art
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/00_musicbrainz.luac
core debug: Buffering 20%
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/01_googleimage.luac
core debug: Buffering 23%
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/02_frenchtv.luac
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/03_lastfm.luac
core debug: Buffering 26%
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/art
core debug: no art finder modules matched
core debug: art not found for udp://239.192.4.1:1234
core debug: Buffering 29%
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 debug: found NAL_SPS (sps_id=0)
packetizer_h264 debug: found NAL_PPS (pps_id=0 sps_id=0)
core debug: Buffering 32%
core debug: Buffering 35%
core debug: Buffering 38%
core debug: Buffering 41%
core debug: Buffering 45%
omxil debug: OmxEventHandler (OMX_EventPortSettingsChanged, 131, 0)
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandPortDisable, 131)
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandPortEnable, 131)
omxil debug: -> input 130 (0 streams) (20:1:81920 buffers) (0,16) enabled
omxil debug: -> video H264 - MPEG-4 AVC (part 10) 0x0@0.00 (7,0) (0,0) (0,0,0,0)
omxil debug: -> output 131 (0 streams) (1:1:1382400 buffers) (0,16) enabled
omxil debug: -> video Planar 4:2:0 YUV 1280x720@59.94 (0,20) (1280,720) (0,0,1280,720)
core debug: Buffering 47%
core debug: Buffering 50%
core debug: looking for text renderer module matching "any": 3 candidates
freetype debug: Building font databases.
freetype debug: Took 1 microseconds
freetype debug: Using Serif Bold as font from file /usr/share/fonts/truetype/dejavu/DejaVuSans.ttf
freetype debug: Using Monospace as mono-font from file /usr/share/fonts/truetype/freefont/FreeMono.ttf
freetype debug: using fontsize: 2
core debug: using text renderer module "freetype"
core debug: looking for video filter2 module matching "any": 56 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": 56 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 "omxil_vout": 14 candidates
core debug: Buffering 53%
omxil_vout debug: component OMX.broadcom.audio_capture
omxil_vout debug: component OMX.broadcom.audio_decode
omxil_vout debug: component OMX.broadcom.audio_encode
omxil_vout debug: component OMX.broadcom.audio_render
omxil_vout debug: component OMX.broadcom.audio_mixer
omxil_vout debug: component OMX.broadcom.audio_splitter
omxil_vout debug: component OMX.broadcom.audio_processor
omxil_vout debug: component OMX.broadcom.camera
omxil_vout debug: component OMX.broadcom.clock
omxil_vout debug: component OMX.broadcom.coverage
omxil_vout debug: component OMX.broadcom.egl_render
omxil_vout debug: component OMX.broadcom.image_fx
omxil_vout debug: component OMX.broadcom.image_decode
omxil_vout debug: component OMX.broadcom.image_encode
omxil_vout debug: component OMX.broadcom.image_read
omxil_vout debug: component OMX.broadcom.image_write
omxil_vout debug: component OMX.broadcom.read_media
omxil_vout debug: component OMX.broadcom.resize
omxil_vout debug: component OMX.broadcom.source
omxil_vout debug: component OMX.broadcom.text_scheduler
omxil_vout debug: component OMX.broadcom.transition
omxil_vout debug: component OMX.broadcom.video_decode
omxil_vout debug: component OMX.broadcom.video_encode
omxil_vout debug: component OMX.broadcom.video_render
omxil_vout debug: component OMX.broadcom.video_scheduler
omxil_vout debug: component OMX.broadcom.video_splitter
omxil_vout debug: component OMX.broadcom.visualisation
omxil_vout debug: component OMX.broadcom.write_media
omxil_vout debug: component OMX.broadcom.write_still
omxil_vout debug: found 1 matching components for role iv_renderer
omxil_vout debug: - OMX.broadcom.video_render
omxil_vout debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateIdle)
omxil_vout debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateExecuting)
core debug: VoutDisplayEvent 'fullscreen' 1
core debug: using vout display module "omxil_vout"
core warning: Not enough direct buffers, using system memory
core debug: original format sz 1280x720, of (0,0), vsz 1280x720, 4cc I420, sar 1:1, msk r0x0 g0x0 b0x0
core debug: removing module "freetype"
core debug: looking for text renderer module matching "any": 3 candidates
freetype debug: Building font databases.
freetype debug: Took 0 microseconds
freetype debug: Using Serif Bold as font from file /usr/share/fonts/truetype/dejavu/DejaVuSans.ttf
freetype debug: Using Monospace as mono-font from file /usr/share/fonts/truetype/freefont/FreeMono.ttf
freetype debug: using fontsize: 2
core debug: using text renderer module "freetype"
core debug: Buffering 56%
core debug: End of video preroll
core debug: Received first picture
core debug: looking for video blending module matching "any": 1 candidates
core debug: using video blending module "blend"
core debug: Buffering 59%
core debug: Detected interlaced video
core debug: deinterlace 0, mode blend, is_needed 1
core error: Failed to set fullscreen
core error: Failed to change zoom
core error: Failed to set on top
core debug: Buffering 62%
core debug: Buffering 65%
core debug: Buffering 68%
core debug: Buffering 71%
core debug: Buffering 74%
core debug: Buffering 77%
core debug: Buffering 80%
core debug: Buffering 83%
core debug: Buffering 86%
core debug: Buffering 90%
ts debug: PSINewTableCallBack: table 0x42(66) ext=0x1(1)
ts debug: SDTCallBack called
ts debug: new SDT ts_id=1 version=5 current_next=1 network_id=1
ts debug: * service id=257 eit schedule=0 present=0 running=0 free_ca=0
ts debug: - type=1 provider=TV-Provider name=TV-101
core debug: EsOutProgramMeta: number=257
ts debug: pid[16] unknown
core debug: Buffering 92%
core debug: Buffering 96%
core debug: Buffering 98%
core debug: Stream buffering done (1019 ms in 945 ms)
core debug: Decoder wait done in 0 ms
core debug: inserting 5004 zeroes
core debug: auto hiding mouse cursor
core warning: picture is too late to be displayed (missing 29 ms)
core warning: picture is too late to be displayed (missing 27 ms)
core warning: picture is too late to be displayed (missing 28 ms)
core warning: picture is too late to be displayed (missing 40 ms)
core warning: picture is too late to be displayed (missing 44 ms)
core warning: picture is too late to be displayed (missing 45 ms)
core warning: picture is too late to be displayed (missing 50 ms)
core warning: picture is too late to be displayed (missing 48 ms)
core warning: picture is too late to be displayed (missing 48 ms)
core warning: picture is too late to be displayed (missing 50 ms)
core warning: picture is too late to be displayed (missing 60 ms)
core warning: picture is too late to be displayed (missing 65 ms)
core warning: picture is too late to be displayed (missing 66 ms)
core warning: picture is too late to be displayed (missing 85 ms)
core warning: picture is too late to be displayed (missing 89 ms)
core warning: picture is too late to be displayed (missing 89 ms)
core warning: picture is too late to be displayed (missing 99 ms)
core warning: picture is too late to be displayed (missing 95 ms)
core warning: picture is too late to be displayed (missing 82 ms)
core warning: picture is too late to be displayed (missing 103 ms)
core warning: picture is too late to be displayed (missing 101 ms)
core warning: picture is too late to be displayed (missing 108 ms)
core warning: picture is too late to be displayed (missing 101 ms)
core warning: picture is too late to be displayed (missing 119 ms)
core warning: picture is too late to be displayed (missing 116 ms)
core warning: picture is too late to be displayed (missing 115 ms)
core warning: picture is too late to be displayed (missing 123 ms)
core warning: picture is too late to be displayed (missing 120 ms)
core warning: picture is too late to be displayed (missing 117 ms)
core warning: picture is too late to be displayed (missing 116 ms)
core warning: picture is too late to be displayed (missing 122 ms)
core warning: picture is too late to be displayed (missing 121 ms)
core warning: picture is too late to be displayed (missing 122 ms)
core warning: picture is too late to be displayed (missing 117 ms)
.... and going on like forever
We use 2.2.8 on RPi 3 to show udp and rtp IPTV usually without issues.
We now have udp streams that are locally generated from jpg stills (slideshows) and audio, encoded as H.264 video.
These streams can be perfectly received and played on a PC - no errors even on level 2.
However, on a RPi there sometimes is no picture at all, sometimes a jaggy one and chopped audio. There are uncountable errors - I add the log until the first few errors that repeat endless from there on below.
What could be the cause for this?
Thanks
McL
core debug: processing request item: udp://239.192.4.1:1234, node: Wiedergabeliste, skip: 0
core debug: resyncing on udp://239.192.4.1:1234
core debug: udp://239.192.4.1:1234 is at 0
core debug: starting playback of the new playlist item
core debug: resyncing on udp://239.192.4.1:1234
core debug: udp://239.192.4.1:1234 is at 0
core debug: creating new input thread
core debug: Creating an input for 'udp://239.192.4.1:1234'
core debug: requesting art for udp://239.192.4.1:1234
core debug: using timeshift granularity of 50 MiB, in path '/tmp'
core debug: `udp://@239.192.4.1:1234' gives access `udp' demux `' path `@239.192.4.1:1234'
core debug: specified demux `any'
core debug: creating demux: access='udp' demux='any' location='@239.192.4.1:1234' file='(null)'
core debug: looking for access_demux module matching "udp": 21 candidates
core debug: no access_demux modules matched
core debug: creating access 'udp' location='@239.192.4.1:1234', path='(null)'
core debug: looking for access module matching "udp": 23 candidates
udp debug: opening server=:0 local=239.192.4.1:1234
core debug: net: opening 239.192.4.1 datagram port 1234
core debug: looking for meta fetcher module matching "any": 1 candidates
core debug: using access module "udp"
core debug: Using block method for AStream*
core debug: starting pre-buffering
core debug: received first data after 9 ms
core debug: prebuffering done 1316 bytes in 0s - 133 KiB/s
core debug: looking for stream_filter module matching "any": 9 candidates
core debug: no stream_filter modules matched
core debug: looking for stream_filter module matching "record": 9 candidates
core debug: using stream_filter module "record"
core debug: creating demux: access='udp' demux='any' location='@239.192.4.1:1234' file='(null)'
core debug: looking for demux module matching "any": 65 candidates
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/fetcher
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/fetcher
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/fetcher/tvrage.luac
core warning: cannot load module `/usr/lib/vlc/plugins/demux/libmkv_plugin.so' (/usr/lib/vlc/plugins/demux/libmkv_plugin.so: undefined symbol: _ZNK7libebml10EbmlStringcvRKSsEv)
core error: corrupt module: /usr/lib/vlc/plugins/demux/libmkv_plugin.so
mod debug: MOD validation failed (ext=)
ts debug: Force Seek Per Percent: PCR's not found,
ts debug: pid[257] unknown
ts debug: pid[259] unknown
ts debug: pid[258] unknown
ts debug: PATCallBack called
ts debug: new PAT ts_id=1 version=5 current_next=1
ts debug: * number=0 pid=16
ts debug: * number=257 pid=256
ts debug: PMTCallBack called
ts debug: new PMT program number=257 version=5 pid_pcr=259
ts debug: * es pid=257 type=27 fcc=h264
core debug: selecting program id=257
ts debug: * es pid=258 type=3 fcc=mpga
core debug: using demux module "ts"
core debug: looking for decoder module matching "any": 46 candidates
omxil debug: fmt in:h264, out:
omxil debug: component OMX.broadcom.audio_capture
omxil debug: component OMX.broadcom.audio_decode
omxil debug: component OMX.broadcom.audio_encode
omxil debug: component OMX.broadcom.audio_render
omxil debug: component OMX.broadcom.audio_mixer
omxil debug: component OMX.broadcom.audio_splitter
omxil debug: component OMX.broadcom.audio_processor
omxil debug: component OMX.broadcom.camera
omxil debug: component OMX.broadcom.clock
omxil debug: component OMX.broadcom.coverage
omxil debug: component OMX.broadcom.egl_render
omxil debug: component OMX.broadcom.image_fx
omxil debug: component OMX.broadcom.image_decode
omxil debug: component OMX.broadcom.image_encode
omxil debug: component OMX.broadcom.image_read
omxil debug: component OMX.broadcom.image_write
omxil debug: component OMX.broadcom.read_media
omxil debug: component OMX.broadcom.resize
omxil debug: component OMX.broadcom.source
omxil debug: component OMX.broadcom.text_scheduler
omxil debug: component OMX.broadcom.transition
omxil debug: component OMX.broadcom.video_decode
omxil debug: component OMX.broadcom.video_encode
omxil debug: component OMX.broadcom.video_render
omxil debug: component OMX.broadcom.video_scheduler
omxil debug: component OMX.broadcom.video_splitter
omxil debug: component OMX.broadcom.visualisation
omxil debug: component OMX.broadcom.write_media
omxil debug: component OMX.broadcom.write_still
omxil debug: found 1 matching components for role video_decoder.avc
omxil debug: - OMX.broadcom.video_decode
omxil debug: loaded component OMX.broadcom.video_decode
omxil debug: found 0 audio ports
omxil debug: found 0 image ports
omxil debug: found 2 video ports
omxil debug: -> input 130 (0 streams) (20:1:81920 buffers) (0,16) enabled
omxil debug: -> video MPEG-4 Video 0x0@0.00 (4,0) (0,0) (0,0,0,0)
omxil debug: -> output 131 (0 streams) (1:1:115200 buffers) (0,16) enabled
omxil debug: -> video Planar 4:2:0 YUV 320x240@0.00 (0,20) (320,240) (0,0,320,240)
omxil debug: Enabled aspect ratio notifications
omxil debug: StartWithValidFrame disabled.
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateIdle)
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateExecuting)
omxil debug: -> input 130 (0 streams) (20:1:81920 buffers) (0,16) enabled
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/fetcher/tvrage.luac
omxil debug: -> video H264 - MPEG-4 AVC (part 10) 0x0@0.00 (7,0) (0,0) (0,0,0,0)
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/fetcher
core debug: no meta fetcher modules matched
core debug: searching art for udp://239.192.4.1:1234
omxil debug: -> output 131 (0 streams) (1:1:0 buffers) (0,16) enabled
omxil debug: -> video Planar 4:2:0 YUV 0x0@0.00 (0,20) (0,240) (0,0,0,0)
core debug: using decoder module "omxil"
core debug: looking for art finder module matching "any": 2 candidates
core debug: looking for packetizer module matching "any": 23 candidates
core debug: using packetizer module "packetizer_h264"
qt4 debug: IM: Setting an input
core debug: looking for decoder module matching "any": 46 candidates
core debug: using decoder module "mpeg_audio"
ts debug: DEMUX_SET_GROUP 0 (nil)
core debug: looking for meta reader module matching "any": 2 candidates
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/art
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/art
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/00_musicbrainz.luac
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/reader
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/reader
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/reader/filename.luac
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/00_musicbrainz.luac
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/01_googleimage.luac
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/reader
core debug: no meta reader modules matched
core debug: `udp://@239.192.4.1:1234' successfully opened
ts warning: first packet for pid=257 cc=0xf
ts debug: pid[1] unknown
ts warning: discontinuity received 0xb instead of 0x6 (pid=257)
ts warning: first packet for pid=258 cc=0x9
core debug: Buffering 0%
packetizer_h264 warning: waiting for SPS/PPS
core debug: Buffering 2%
mpeg_audio debug: MPGA channels:2 samplerate:48000 bitrate:256
core debug: reusing audio output
core debug: Buffering 5%
packetizer_h264 warning: waiting for SPS/PPS
alsa debug: using ALSA device: default
alsa debug: Hardware PCM card 1 'USB AUDIO CODEC' device 0 subdevice 0
alsa debug: device name : USB Audio
alsa debug: device ID : USB Audio
alsa debug: subdevice name: subdevice #0
alsa debug: initial hardware setup: ACCESS: MMAP_INTERLEAVED RW_INTERLEAVED FORMAT: S8 S16_LE SUBFORMAT: STD SAMPLE_BITS: [8 16] FRAME_BITS: [8 32] CHANNELS: [1 2] RATE: [32000 48000] PERIOD_TIME: [1000 16384000] PERIOD_SIZE: [32 524288] PERIOD_BYTES: [64 524288] PERIODS: [2 1024] BUFFER_TIME: (1333 32768000] BUFFER_SIZE: [64 1048576] BUFFER_BYTES: [64 1048576] TICK_TIME: ALL
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
alsa debug: using channels map 0, type 1, 2 channel(s)
alsa debug: final HW setup: ACCESS: RW_INTERLEAVED FORMAT: S16_LE SUBFORMAT: STD SAMPLE_BITS: 16 FRAME_BITS: 32 CHANNELS: 2 RATE: 48000 PERIOD_TIME: 40000 PERIOD_SIZE: 1920 PERIOD_BYTES: 7680 PERIODS: 75 BUFFER_TIME: 3000000 BUFFER_SIZE: 144000 BUFFER_BYTES: 576000 TICK_TIME: 0
alsa debug: initial software parameters: tstamp_mode: NONE tstamp_type: MONOTONIC period_step: 1 avail_min: 1920 start_threshold: 1 stop_threshold: 144000 silence_threshold: 0 silence_size: 0 boundary: 1179648000
alsa debug: final software parameters: tstamp_mode: NONE tstamp_type: MONOTONIC period_step: 1 avail_min: 1920 start_threshold: 1 stop_threshold: 144000 silence_threshold: 0 silence_size: 0 boundary: 1179648000
core debug: output 's16l' 48000 Hz Stereo frame=1 samples/4 bytes
core debug: looking for audio volume module matching "any": 2 candidates
core debug: using audio volume module "integer_mixer"
core debug: input 'mpga' 48000 Hz Stereo frame=1152 samples/1161 bytes
core debug: looking for audio filter module matching "scaletempo": 14 candidates
scaletempo debug: format: 48000 rate, 2 nch, 4 bps, fl32
scaletempo debug: params: 30 stride, 0.200 overlap, 14 search
scaletempo debug: 1.000 scale, 1440.000 stride_in, 1440 stride_out, 1152 standing, 288 overlap, 672 search, 2400 queue, fl32 mode
core debug: using audio filter module "scaletempo"
core debug: conversion: 'mpga'->'f32l' 48000 Hz->48000 Hz Stereo->Stereo
core debug: looking for audio converter module matching "any": 12 candidates
core debug: no audio converter modules matched
core debug: Buffering 8%
core debug: looking for audio converter module matching "any": 12 candidates
mpgatofixed32 debug: mpga->f32l, bits per sample: 32
core debug: using audio converter module "mpgatofixed32"
core debug: conversion pipeline complete
core debug: conversion: 'f32l'->'s16l' 48000 Hz->48000 Hz Stereo->Stereo
core debug: looking for audio converter module matching "any": 12 candidates
audio_format debug: f32l->s16l, bits per sample: 0->16
core debug: using audio converter module "audio_format"
core debug: conversion pipeline complete
core debug: looking for audio resampler module matching "any": 3 candidates
core debug: using audio resampler module "ugly_resampler"
core debug: End of audio preroll
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/01_googleimage.luac
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/02_frenchtv.luac
packetizer_h264 warning: waiting for SPS/PPS
core debug: Buffering 11%
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/02_frenchtv.luac
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/03_lastfm.luac
packetizer_h264 warning: waiting for SPS/PPS
core debug: Buffering 14%
lua debug: skipping script (unmatched scope) /usr/lib/vlc/lua/meta/art/03_lastfm.luac
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/art
core debug: no art finder modules matched
core debug: looking for meta fetcher module matching "any": 1 candidates
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/fetcher
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/fetcher
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/fetcher/tvrage.luac
core debug: Buffering 17%
core debug: using meta fetcher module "lua"
core debug: removing module "lua"
core debug: searching art for udp://239.192.4.1:1234
core debug: looking for art finder module matching "any": 2 candidates
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua scripts in /home/pi/.local/share/vlc/lua/meta/art
lua debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/art
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/00_musicbrainz.luac
core debug: Buffering 20%
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/01_googleimage.luac
core debug: Buffering 23%
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/02_frenchtv.luac
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 warning: waiting for SPS/PPS
lua debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/art/03_lastfm.luac
core debug: Buffering 26%
lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/art
core debug: no art finder modules matched
core debug: art not found for udp://239.192.4.1:1234
core debug: Buffering 29%
packetizer_h264 warning: waiting for SPS/PPS
packetizer_h264 debug: found NAL_SPS (sps_id=0)
packetizer_h264 debug: found NAL_PPS (pps_id=0 sps_id=0)
core debug: Buffering 32%
core debug: Buffering 35%
core debug: Buffering 38%
core debug: Buffering 41%
core debug: Buffering 45%
omxil debug: OmxEventHandler (OMX_EventPortSettingsChanged, 131, 0)
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandPortDisable, 131)
omxil debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandPortEnable, 131)
omxil debug: -> input 130 (0 streams) (20:1:81920 buffers) (0,16) enabled
omxil debug: -> video H264 - MPEG-4 AVC (part 10) 0x0@0.00 (7,0) (0,0) (0,0,0,0)
omxil debug: -> output 131 (0 streams) (1:1:1382400 buffers) (0,16) enabled
omxil debug: -> video Planar 4:2:0 YUV 1280x720@59.94 (0,20) (1280,720) (0,0,1280,720)
core debug: Buffering 47%
core debug: Buffering 50%
core debug: looking for text renderer module matching "any": 3 candidates
freetype debug: Building font databases.
freetype debug: Took 1 microseconds
freetype debug: Using Serif Bold as font from file /usr/share/fonts/truetype/dejavu/DejaVuSans.ttf
freetype debug: Using Monospace as mono-font from file /usr/share/fonts/truetype/freefont/FreeMono.ttf
freetype debug: using fontsize: 2
core debug: using text renderer module "freetype"
core debug: looking for video filter2 module matching "any": 56 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": 56 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 "omxil_vout": 14 candidates
core debug: Buffering 53%
omxil_vout debug: component OMX.broadcom.audio_capture
omxil_vout debug: component OMX.broadcom.audio_decode
omxil_vout debug: component OMX.broadcom.audio_encode
omxil_vout debug: component OMX.broadcom.audio_render
omxil_vout debug: component OMX.broadcom.audio_mixer
omxil_vout debug: component OMX.broadcom.audio_splitter
omxil_vout debug: component OMX.broadcom.audio_processor
omxil_vout debug: component OMX.broadcom.camera
omxil_vout debug: component OMX.broadcom.clock
omxil_vout debug: component OMX.broadcom.coverage
omxil_vout debug: component OMX.broadcom.egl_render
omxil_vout debug: component OMX.broadcom.image_fx
omxil_vout debug: component OMX.broadcom.image_decode
omxil_vout debug: component OMX.broadcom.image_encode
omxil_vout debug: component OMX.broadcom.image_read
omxil_vout debug: component OMX.broadcom.image_write
omxil_vout debug: component OMX.broadcom.read_media
omxil_vout debug: component OMX.broadcom.resize
omxil_vout debug: component OMX.broadcom.source
omxil_vout debug: component OMX.broadcom.text_scheduler
omxil_vout debug: component OMX.broadcom.transition
omxil_vout debug: component OMX.broadcom.video_decode
omxil_vout debug: component OMX.broadcom.video_encode
omxil_vout debug: component OMX.broadcom.video_render
omxil_vout debug: component OMX.broadcom.video_scheduler
omxil_vout debug: component OMX.broadcom.video_splitter
omxil_vout debug: component OMX.broadcom.visualisation
omxil_vout debug: component OMX.broadcom.write_media
omxil_vout debug: component OMX.broadcom.write_still
omxil_vout debug: found 1 matching components for role iv_renderer
omxil_vout debug: - OMX.broadcom.video_render
omxil_vout debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateIdle)
omxil_vout debug: OmxEventHandler (OMX_EventCmdComplete, OMX_CommandStateSet, OMX_StateExecuting)
core debug: VoutDisplayEvent 'fullscreen' 1
core debug: using vout display module "omxil_vout"
core warning: Not enough direct buffers, using system memory
core debug: original format sz 1280x720, of (0,0), vsz 1280x720, 4cc I420, sar 1:1, msk r0x0 g0x0 b0x0
core debug: removing module "freetype"
core debug: looking for text renderer module matching "any": 3 candidates
freetype debug: Building font databases.
freetype debug: Took 0 microseconds
freetype debug: Using Serif Bold as font from file /usr/share/fonts/truetype/dejavu/DejaVuSans.ttf
freetype debug: Using Monospace as mono-font from file /usr/share/fonts/truetype/freefont/FreeMono.ttf
freetype debug: using fontsize: 2
core debug: using text renderer module "freetype"
core debug: Buffering 56%
core debug: End of video preroll
core debug: Received first picture
core debug: looking for video blending module matching "any": 1 candidates
core debug: using video blending module "blend"
core debug: Buffering 59%
core debug: Detected interlaced video
core debug: deinterlace 0, mode blend, is_needed 1
core error: Failed to set fullscreen
core error: Failed to change zoom
core error: Failed to set on top
core debug: Buffering 62%
core debug: Buffering 65%
core debug: Buffering 68%
core debug: Buffering 71%
core debug: Buffering 74%
core debug: Buffering 77%
core debug: Buffering 80%
core debug: Buffering 83%
core debug: Buffering 86%
core debug: Buffering 90%
ts debug: PSINewTableCallBack: table 0x42(66) ext=0x1(1)
ts debug: SDTCallBack called
ts debug: new SDT ts_id=1 version=5 current_next=1 network_id=1
ts debug: * service id=257 eit schedule=0 present=0 running=0 free_ca=0
ts debug: - type=1 provider=TV-Provider name=TV-101
core debug: EsOutProgramMeta: number=257
ts debug: pid[16] unknown
core debug: Buffering 92%
core debug: Buffering 96%
core debug: Buffering 98%
core debug: Stream buffering done (1019 ms in 945 ms)
core debug: Decoder wait done in 0 ms
core debug: inserting 5004 zeroes
core debug: auto hiding mouse cursor
core warning: picture is too late to be displayed (missing 29 ms)
core warning: picture is too late to be displayed (missing 27 ms)
core warning: picture is too late to be displayed (missing 28 ms)
core warning: picture is too late to be displayed (missing 40 ms)
core warning: picture is too late to be displayed (missing 44 ms)
core warning: picture is too late to be displayed (missing 45 ms)
core warning: picture is too late to be displayed (missing 50 ms)
core warning: picture is too late to be displayed (missing 48 ms)
core warning: picture is too late to be displayed (missing 48 ms)
core warning: picture is too late to be displayed (missing 50 ms)
core warning: picture is too late to be displayed (missing 60 ms)
core warning: picture is too late to be displayed (missing 65 ms)
core warning: picture is too late to be displayed (missing 66 ms)
core warning: picture is too late to be displayed (missing 85 ms)
core warning: picture is too late to be displayed (missing 89 ms)
core warning: picture is too late to be displayed (missing 89 ms)
core warning: picture is too late to be displayed (missing 99 ms)
core warning: picture is too late to be displayed (missing 95 ms)
core warning: picture is too late to be displayed (missing 82 ms)
core warning: picture is too late to be displayed (missing 103 ms)
core warning: picture is too late to be displayed (missing 101 ms)
core warning: picture is too late to be displayed (missing 108 ms)
core warning: picture is too late to be displayed (missing 101 ms)
core warning: picture is too late to be displayed (missing 119 ms)
core warning: picture is too late to be displayed (missing 116 ms)
core warning: picture is too late to be displayed (missing 115 ms)
core warning: picture is too late to be displayed (missing 123 ms)
core warning: picture is too late to be displayed (missing 120 ms)
core warning: picture is too late to be displayed (missing 117 ms)
core warning: picture is too late to be displayed (missing 116 ms)
core warning: picture is too late to be displayed (missing 122 ms)
core warning: picture is too late to be displayed (missing 121 ms)
core warning: picture is too late to be displayed (missing 122 ms)
core warning: picture is too late to be displayed (missing 117 ms)
.... and going on like forever