Late packets, dropped packets, audio dropouts

[tcc]

Hi,

I've been getting audio dropouts when streaming out mp3 files using any of the 1.0.x series of players. The files are streamed using #duplicate. Oddly, the drop outs occur far less frequently when streaming out WMA Lossless or WMA 128 kbit files, possibly because these files are streamed using #transcode to mpeg. ??

The mp3 files are encoded at 192 CBR. I have also tested with 256 VBR mp3, tested using different computers and OS (win 2003, Win 7), tested back to vlc 101, and forward to 104 and 11x, and tried a few params including --file-caching, -udp-caching, -sout-udp-caching. --sout-mux-caching, all with same results.

The message log shows a lot of late packets and input file re-buffering going on for some reason. Not sure why this would happen when all computers are fast CPU and disk and on a GigE LAN, and the files are ordinary mp3 encodes done with latest MediaMonkey.

I can provide sample files if needed.

Regards,

Tim

Here is sout chain.

--sout=#duplicate{dst=std
{access=udp,mux=ts,dst=mc2.home.local:1234},dst=std
{access=udp,mux=ts,dst=mc3.home.local:1234},dst=std
{access=udp,mux=ts,dst=lt5.home.local:1234},dst=std
{access=udp,mux=ts,dst=dt2.home.local:1234}}
--sout-keep --file-caching=300

Message log sections are below.

--------- Near beginning of Message Log

mpeg_audio debug: emulated startcode (no startcode on following frame)
main debug: EOF reached
main debug: finished input
main debug: thread times: real 3m38.609375s, kernel 0m0.000000s, user 0m0.000000s
main debug: removing module "mpeg_audio"
main debug: killing decoder fourcc `mpga', 0 PES in FIFO
main debug: removing a sout input (sout_input:0x2401790)
mux_ts debug: removing input pid=68
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
mux_ts debug: removing input pid=68
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
mux_ts debug: removing input pid=68
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
mux_ts debug: removing input pid=68
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
main debug: removing module "mpeg_audio"
main debug: removing module "es"
main debug: removing module "stream_filter_record"
main debug: removing module "access_file"
main debug: Program doesn't contain anymore ES
main debug: dead input
main debug: thread ended
main debug: thread times: real 3m38.625000s, kernel 0m0.687500s, user 0m1.187500s
main debug: changing item without a request (current 0/55)
main debug: using item 1
main debug: starting new item
main debug: creating new input thread
main debug: Creating an input for 'So Danco Samba (Only I Dance Samba)'
main debug: thread (input) created at priority 1 (../.././src/input/input.c:230)
main debug: thread started
main debug: reusing sout
main debug: you probably want to use gather stream_out
main debug: using timeshift granularity of 50 MBytes
main debug: using timeshift path 'C:\DOCUME~1\Ms1admin\LOCALS~1\Temp\1'
main debug:

`file:///N:/Audio/Workfiles/MP3/Antonio%20Carlos%20Jobim%20%28192%20CBR%29/The%20Man%20From%20Ipanema/A

ntonio%20Carlos%20Jobim%20-%2002%20-%20So%20Danco%20Samba%20%28Only%20I%20Dance%20Samba%29.mp3' gives

access `file' demux `' path `N:\Audio\Workfiles\MP3\Antonio Carlos Jobim (192 CBR)\The Man From

Ipanema\Antonio Carlos Jobim - 02 - So Danco Samba (Only I Dance Samba).mp3'
main debug: creating demux: access='file' demux='' path='N:\Audio\Workfiles\MP3\Antonio Carlos Jobim

(192 CBR)\The Man From Ipanema\Antonio Carlos Jobim - 02 - So Danco Samba (Only I Dance Samba).mp3'
main debug: looking for access_demux module: 1 candidate
main warning: no access_demux module matching "file" could be loaded
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: creating access 'file' path='N:\Audio\Workfiles\MP3\Antonio Carlos Jobim (192 CBR)\The Man

From Ipanema\Antonio Carlos Jobim - 02 - So Danco Samba (Only I Dance Samba).mp3'
main debug: looking for access module: 2 candidates
access_file debug: opening file `N:\Audio\Workfiles\MP3\Antonio Carlos Jobim (192 CBR)\The Man From

Ipanema\Antonio Carlos Jobim - 02 - So Danco Samba (Only I Dance Samba).mp3'
access_file warning: Opening remote file, increasing cache: 1000
main debug: using access module "access_file"
main debug: TIMER module_need() : 3.000 ms - Total 3.000 ms / 1 intvls (Avg 3.000 ms)
main debug: Using AStream*Stream
main debug: pre buffering
main debug: received first data after 0 ms
main debug: pre-buffering done 1024 bytes in 0s - 1000000 kbytes/s
main debug: looking for stream_filter module: 2 candidates
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: looking for stream_filter module: 1 candidate
main debug: using stream_filter module "stream_filter_record"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: creating demux: access='file' demux='' path='N:\Audio\Workfiles\MP3\Antonio Carlos Jobim

(192 CBR)\The Man From Ipanema\Antonio Carlos Jobim - 02 - So Danco Samba (Only I Dance Samba).mp3'
main debug: ID3v2.3 revision 0 tag found, skipping 294 bytes
main debug: looking for demux module: 50 candidates
es debug: detected format mpga
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "mpeg_audio"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: using demux module "es"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: looking for a subtitle file in C:\Program Files\VideoLAN\VLC\
main debug: starting in async mode
main debug: looking for meta reader module: 1 candidate
main debug: using meta reader module "taglib"
main debug: TIMER module_need() : 4.000 ms - Total 4.000 ms / 1 intvls (Avg 4.000 ms)
main debug: removing module "taglib"
main debug:

`file:///N:/Audio/Workfiles/MP3/Antonio%20Carlos%20Jobim%20%28192%20CBR%29/The%20Man%20From%20Ipanema/A

ntonio%20Carlos%20Jobim%20-%2002%20-%20So%20Danco%20Samba%20%28Only%20I%20Dance%20Samba%29.mp3'

successfully opened
mpeg_audio debug: MPGA channels:2 samplerate:44100 bitrate:192
main debug: selecting program id=0
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "mpeg_audio"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: thread started
main debug: thread (decoder) created at priority 2 (../.././src/input/decoder.c:315)
main debug: Buffering 0%
main debug: switching to sync mode
main debug: Buffering 2%
mpeg_audio debug: MPGA channels:2 samplerate:44100 bitrate:192
main debug: adding a new sout input (sout_input:0x24750f8)
stream_out_duplicate debug: duplicated a new stream codec=mpga (es=0 group=0)
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=69
mux_ts debug: new PCR PID is 69
stream_out_duplicate debug: - added for output 0
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=69
mux_ts debug: new PCR PID is 69
stream_out_duplicate debug: - added for output 1
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=69
mux_ts debug: new PCR PID is 69
stream_out_duplicate debug: - added for output 2
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=69
mux_ts debug: new PCR PID is 69
stream_out_duplicate debug: - added for output 3
main debug: Buffering 5%
main debug: Buffering 7%
main debug: Buffering 10%
main debug: Buffering 13%
main debug: Buffering 15%
main debug: Buffering 18%
main debug: Buffering 20%
main debug: Buffering 23%
main debug: Buffering 26%
main debug: Buffering 28%
main debug: Buffering 31%
main debug: Buffering 33%
main debug: Buffering 36%
main debug: Buffering 39%
main debug: Buffering 41%
main debug: Buffering 44%
main debug: Buffering 47%
main debug: Buffering 49%
main debug: Buffering 52%
main debug: Buffering 54%
main debug: Buffering 57%
main debug: Buffering 60%
main debug: Buffering 62%
main debug: Buffering 65%
main debug: Buffering 67%
main debug: Buffering 70%
main debug: Buffering 73%
main debug: Buffering 75%
main debug: Buffering 78%
main debug: Buffering 80%
main debug: Buffering 83%
main debug: Buffering 86%
main debug: Buffering 88%
main debug: Buffering 91%
main debug: Buffering 94%
main debug: Buffering 96%
main debug: Buffering 99%
main debug: Stream buffering done (1018 ms in 0 ms)
main debug: Decoder buffering done in 0 ms
qt4 debug: IM: Deleting the input
qt4 debug: Updating the geometry
qt4 debug: Updating the geometry
main debug: TIMER input launching for 'Antonio Carlos Jobim - 01 - Passarim.mp3' : 23.000 ms - Total

23.000 ms / 1 intvls (Avg 23.000 ms)
qt4 debug: IM: Setting an input
qt4 debug: Updating the geometry
qt4 debug: Updating the geometry
access_output_udp debug: mmh, packets in the past (977526)
access_output_udp debug: mmh, packets in the past (977526)
access_output_udp debug: mmh, packets in the past (977526)
access_output_udp debug: mmh, packets in the past (977526)
access_output_udp debug: packet has been sent too late (977854)
access_output_udp debug: packet has been sent too late (977854)
access_output_udp debug: packet has been sent too late (977854)
access_output_udp debug: packet has been sent too late (934829)
access_output_udp debug: packet has been sent too late (977854)
access_output_udp debug: packet has been sent too late (934829)
access_output_udp debug: packet has been sent too late (934829)
access_output_udp debug: packet has been sent too late (891804)
access_output_udp debug: packet has been sent too late (934829)
access_output_udp debug: packet has been sent too late (891804)
access_output_udp debug: packet has been sent too late (891804)
access_output_udp debug: packet has been sent too late (848779)
access_output_udp debug: packet has been sent too late (891804)
access_output_udp debug: packet has been sent too late (848779)
access_output_udp debug: packet has been sent too late (848779)
access_output_udp debug: packet has been sent too late (805754)
access_output_udp debug: packet has been sent too late (848779)
access_output_udp debug: packet has been sent too late (805754)
access_output_udp debug: packet has been sent too late (805754)
access_output_udp debug: packet has been sent too late (762729)
access_output_udp debug: packet has been sent too late (805754)
access_output_udp debug: packet has been sent too late (762729)
access_output_udp debug: packet has been sent too late (762729)
access_output_udp debug: packet has been sent too late (719703)
access_output_udp debug: packet has been sent too late (762729)
access_output_udp debug: packet has been sent too late (719703)
access_output_udp debug: packet has been sent too late (719703)
access_output_udp debug: packet has been sent too late (676678)
access_output_udp debug: packet has been sent too late (719703)
access_output_udp debug: packet has been sent too late (676678)
access_output_udp debug: packet has been sent too late (676678)
access_output_udp debug: packet has been sent too late (633653)
access_output_udp debug: packet has been sent too late (633653)
access_output_udp debug: packet has been sent too late (676678)
access_output_udp debug: packet has been sent too late (633653)
access_output_udp debug: packet has been sent too late (590627)
access_output_udp debug: packet has been sent too late (590627)
access_output_udp debug: packet has been sent too late (633653)
access_output_udp debug: packet has been sent too late (590627)
access_output_udp debug: packet has been sent too late (547602)
access_output_udp debug: packet has been sent too late (547602)
access_output_udp debug: packet has been sent too late (590627)
access_output_udp debug: packet has been sent too late (547602)
access_output_udp debug: packet has been sent too late (504577)
access_output_udp debug: packet has been sent too late (504577)
access_output_udp debug: packet has been sent too late (547602)
access_output_udp debug: packet has been sent too late (504577)
access_output_udp debug: packet has been sent too late (461552)
access_output_udp debug: packet has been sent too late (461552)
access_output_udp debug: packet has been sent too late (504577)
access_output_udp debug: packet has been sent too late (461552)
access_output_udp debug: packet has been sent too late (418527)
access_output_udp debug: packet has been sent too late (418527)
access_output_udp debug: packet has been sent too late (461552)
access_output_udp debug: packet has been sent too late (418527)
access_output_udp debug: packet has been sent too late (375502)
access_output_udp debug: packet has been sent too late (375502)
access_output_udp debug: packet has been sent too late (418527)
access_output_udp debug: packet has been sent too late (375502)
access_output_udp debug: packet has been sent too late (332477)
access_output_udp debug: packet has been sent too late (332477)
access_output_udp debug: packet has been sent too late (375502)
access_output_udp debug: packet has been sent too late (332477)
access_output_udp debug: packet has been sent too late (289451)
access_output_udp debug: packet has been sent too late (289451)
access_output_udp debug: packet has been sent too late (332477)
access_output_udp debug: packet has been sent too late (289451)
access_output_udp debug: packet has been sent too late (246426)
access_output_udp debug: packet has been sent too late (246426)
access_output_udp debug: packet has been sent too late (289451)
access_output_udp debug: packet has been sent too late (246426)
access_output_udp debug: packet has been sent too late (203401)
access_output_udp debug: packet has been sent too late (203401)
access_output_udp debug: packet has been sent too late (246426)
access_output_udp debug: packet has been sent too late (203401)
access_output_udp debug: packet has been sent too late (160375)
access_output_udp debug: packet has been sent too late (160375)
access_output_udp debug: packet has been sent too late (203401)
access_output_udp debug: packet has been sent too late (160375)
access_output_udp debug: packet has been sent too late (117350)
access_output_udp debug: packet has been sent too late (117350)
access_output_udp debug: packet has been sent too late (160375)
access_output_udp debug: packet has been sent too late (117350)
access_output_udp debug: packet has been sent too late (74325)
access_output_udp debug: packet has been sent too late (74325)
access_output_udp debug: packet has been sent too late (117350)
access_output_udp debug: packet has been sent too late (74325)
access_output_udp debug: packet has been sent too late (31300)
access_output_udp debug: packet has been sent too late (31300)
access_output_udp debug: packet has been sent too late (74325)
access_output_udp debug: packet has been sent too late (31300)
access_output_udp debug: packet has been sent too late (31300)

--------- A section later in Message Log

mpeg_audio debug: emulated startcode (no startcode on following frame)
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m16.750000s, kernel 0m0.000000s, user 0m0.000000s
main debug: removing module "mpeg_audio"
main debug: killing decoder fourcc `mpga', 0 PES in FIFO
main debug: removing a sout input (sout_input:0x247f3c0)
mux_ts debug: removing input pid=78
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
mux_ts debug: removing input pid=78
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
mux_ts debug: removing input pid=78
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
mux_ts debug: removing input pid=78
mux_ts debug: new PCR PID is 8191
main warning: no more input streams for this mux
main debug: removing module "mpeg_audio"
main debug: removing module "es"
main debug: removing module "stream_filter_record"
main debug: removing module "access_file"
main debug: Program doesn't contain anymore ES
main debug: thread ended
main debug: dead input
main debug: thread times: real 2m16.750000s, kernel 0m0.234375s, user 0m0.578125s
main debug: changing item without a request (current 10/55)
main debug: using item 11
main debug: starting new item
main debug: creating new input thread
main debug: Creating an input for 'Borzeguim'
main debug: thread (input) created at priority 1 (../.././src/input/input.c:230)
main debug: thread started
main debug: reusing sout
main debug: you probably want to use gather stream_out
main debug: using timeshift granularity of 50 MBytes
main debug: using timeshift path 'C:\DOCUME~1\Ms1admin\LOCALS~1\Temp\1'
main debug:

`file:///N:/Audio/Workfiles/MP3/Antonio%20Carlos%20Jobim%20%28192%20CBR%29/The%20Man%20From%20Ipanema/A

ntonio%20Carlos%20Jobim%20-%2012%20-%20Borzeguim.mp3' gives access `file' demux `' path

`N:\Audio\Workfiles\MP3\Antonio Carlos Jobim (192 CBR)\The Man From Ipanema\Antonio Carlos Jobim - 12 -

Borzeguim.mp3'
main debug: creating demux: access='file' demux='' path='N:\Audio\Workfiles\MP3\Antonio Carlos Jobim

(192 CBR)\The Man From Ipanema\Antonio Carlos Jobim - 12 - Borzeguim.mp3'
main debug: looking for access_demux module: 1 candidate
main warning: no access_demux module matching "file" could be loaded
main debug: TIMER module_need() : 4.000 ms - Total 4.000 ms / 1 intvls (Avg 4.000 ms)
main debug: creating access 'file' path='N:\Audio\Workfiles\MP3\Antonio Carlos Jobim (192 CBR)\The Man

From Ipanema\Antonio Carlos Jobim - 12 - Borzeguim.mp3'
main debug: looking for access module: 2 candidates
access_file debug: opening file `N:\Audio\Workfiles\MP3\Antonio Carlos Jobim (192 CBR)\The Man From

Ipanema\Antonio Carlos Jobim - 12 - Borzeguim.mp3'
access_file warning: Opening remote file, increasing cache: 1000
main debug: using access module "access_file"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: Using AStream*Stream
main debug: pre buffering
main debug: received first data after 0 ms
main debug: pre-buffering done 1024 bytes in 0s - 1000000 kbytes/s
main debug: looking for stream_filter module: 2 candidates
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: looking for stream_filter module: 1 candidate
main debug: using stream_filter module "stream_filter_record"
main debug: TIMER module_need() : 4.000 ms - Total 4.000 ms / 1 intvls (Avg 4.000 ms)
main debug: creating demux: access='file' demux='' path='N:\Audio\Workfiles\MP3\Antonio Carlos Jobim

(192 CBR)\The Man From Ipanema\Antonio Carlos Jobim - 12 - Borzeguim.mp3'
main debug: ID3v2.3 revision 0 tag found, skipping 712 bytes
main debug: looking for demux module: 50 candidates
es debug: detected format mpga
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "mpeg_audio"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: using demux module "es"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: looking for a subtitle file in C:\Program Files\VideoLAN\VLC\
main debug: starting in async mode
main debug: looking for meta reader module: 1 candidate
main debug: using meta reader module "taglib"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "taglib"
main debug:

`file:///N:/Audio/Workfiles/MP3/Antonio%20Carlos%20Jobim%20%28192%20CBR%29/The%20Man%20From%20Ipanema/A

ntonio%20Carlos%20Jobim%20-%2012%20-%20Borzeguim.mp3' successfully opened
mpeg_audio debug: MPGA channels:2 samplerate:44100 bitrate:192
main debug: selecting program id=0
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "mpeg_audio"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: thread started
main debug: thread (decoder) created at priority 2 (../.././src/input/decoder.c:315)
main debug: Buffering 0%
main debug: switching to sync mode
main debug: Buffering 2%
mpeg_audio debug: MPGA channels:2 samplerate:44100 bitrate:192
main debug: adding a new sout input (sout_input:0x24abd00)
stream_out_duplicate debug: duplicated a new stream codec=mpga (es=0 group=0)
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=79
mux_ts debug: new PCR PID is 79
stream_out_duplicate debug: - added for output 0
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=79
mux_ts debug: new PCR PID is 79
stream_out_duplicate debug: - added for output 1
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=79
mux_ts debug: new PCR PID is 79
stream_out_duplicate debug: - added for output 2
main debug: adding a new input
mux_ts debug: adding input codec=mpga pid=79
mux_ts debug: new PCR PID is 79
stream_out_duplicate debug: - added for output 3
main debug: Buffering 5%
main debug: Buffering 7%
main debug: Buffering 10%
main debug: Buffering 13%
main debug: Buffering 15%
main debug: Buffering 18%
main debug: Buffering 20%
main debug: Buffering 23%
main debug: Buffering 26%
main debug: Buffering 28%
main debug: Buffering 31%
main debug: Buffering 33%
main debug: Buffering 36%
main debug: Buffering 39%
main debug: Buffering 41%
main debug: Buffering 44%
main debug: Buffering 47%
main debug: Buffering 49%
main debug: Buffering 52%
main debug: Buffering 54%
main debug: Buffering 57%
main debug: Buffering 60%
main debug: Buffering 62%
main debug: Buffering 65%
main debug: Buffering 67%
main debug: Buffering 70%
main debug: Buffering 73%
main debug: Buffering 75%
main debug: Buffering 78%
main debug: Buffering 80%
main debug: Buffering 83%
main debug: Buffering 86%
main debug: Buffering 88%
main debug: Buffering 91%
main debug: Buffering 94%
main debug: Buffering 96%
main debug: Buffering 99%
main debug: Stream buffering done (1018 ms in 0 ms)
main debug: Decoder buffering done in 0 ms
qt4 debug: IM: Deleting the input
qt4 debug: Updating the geometry
qt4 debug: Updating the geometry
main debug: TIMER input launching for 'Modinha' : 15.000 ms - Total 15.000 ms / 1 intvls (Avg 15.000

ms)
qt4 debug: IM: Setting an input
qt4 debug: Updating the geometry
qt4 debug: Updating the geometry
access_output_udp debug: mmh, packets in the past (916525)
access_output_udp debug: mmh, packets in the past (916525)
access_output_udp debug: mmh, packets in the past (916525)
access_output_udp debug: mmh, packets in the past (916525)
access_output_udp debug: packet has been sent too late (917000)
access_output_udp debug: packet has been sent too late (917000)
access_output_udp debug: packet has been sent too late (917000)
access_output_udp debug: packet has been sent too late (917000)
access_output_udp debug: packet has been sent too late (873975)
access_output_udp debug: packet has been sent too late (873975)
access_output_udp debug: packet has been sent too late (873975)
access_output_udp debug: packet has been sent too late (873975)
access_output_udp debug: packet has been sent too late (830950)
access_output_udp debug: packet has been sent too late (830950)
access_output_udp debug: packet has been sent too late (830950)
access_output_udp debug: packet has been sent too late (830950)
access_output_udp debug: packet has been sent too late (787925)
access_output_udp debug: packet has been sent too late (787925)
access_output_udp debug: packet has been sent too late (787925)
access_output_udp debug: packet has been sent too late (787925)
access_output_udp debug: packet has been sent too late (744900)
access_output_udp debug: packet has been sent too late (744900)
access_output_udp debug: packet has been sent too late (744900)
access_output_udp debug: packet has been sent too late (744900)
access_output_udp debug: packet has been sent too late (701875)
access_output_udp debug: packet has been sent too late (701875)
access_output_udp debug: packet has been sent too late (701875)
access_output_udp debug: packet has been sent too late (701875)
access_output_udp debug: packet has been sent too late (658850)
access_output_udp debug: packet has been sent too late (658850)
access_output_udp debug: packet has been sent too late (658850)
access_output_udp debug: packet has been sent too late (658850)
access_output_udp debug: packet has been sent too late (615824)
access_output_udp debug: packet has been sent too late (615824)
access_output_udp debug: packet has been sent too late (615824)
access_output_udp debug: packet has been sent too late (615824)
access_output_udp debug: packet has been sent too late (572799)
access_output_udp debug: packet has been sent too late (572799)
access_output_udp debug: packet has been sent too late (572799)
access_output_udp debug: packet has been sent too late (572799)
access_output_udp debug: packet has been sent too late (529774)
access_output_udp debug: packet has been sent too late (529774)
access_output_udp debug: packet has been sent too late (529774)
access_output_udp debug: packet has been sent too late (529774)
access_output_udp debug: packet has been sent too late (486749)
access_output_udp debug: packet has been sent too late (486749)
access_output_udp debug: packet has been sent too late (486749)
access_output_udp debug: packet has been sent too late (486749)
access_output_udp debug: packet has been sent too late (443724)
access_output_udp debug: packet has been sent too late (443724)
access_output_udp debug: packet has been sent too late (443724)
access_output_udp debug: packet has been sent too late (443724)
access_output_udp debug: packet has been sent too late (400698)
access_output_udp debug: packet has been sent too late (400698)
access_output_udp debug: packet has been sent too late (400698)
access_output_udp debug: packet has been sent too late (400698)
access_output_udp debug: packet has been sent too late (357673)
access_output_udp debug: packet has been sent too late (357673)
access_output_udp debug: packet has been sent too late (357673)
access_output_udp debug: packet has been sent too late (357673)
access_output_udp debug: packet has been sent too late (314648)
access_output_udp debug: packet has been sent too late (314648)
access_output_udp debug: packet has been sent too late (314648)
access_output_udp debug: packet has been sent too late (314648)
access_output_udp debug: packet has been sent too late (271623)
access_output_udp debug: packet has been sent too late (271623)
access_output_udp debug: packet has been sent too late (271623)
access_output_udp debug: packet has been sent too late (271623)
access_output_udp debug: packet has been sent too late (228598)
access_output_udp debug: packet has been sent too late (228598)
access_output_udp debug: packet has been sent too late (228598)
access_output_udp debug: packet has been sent too late (228598)
access_output_udp debug: packet has been sent too late (185572)
access_output_udp debug: packet has been sent too late (185572)
access_output_udp debug: packet has been sent too late (185572)
access_output_udp debug: packet has been sent too late (185572)
access_output_udp debug: packet has been sent too late (142547)
access_output_udp debug: packet has been sent too late (142547)
access_output_udp debug: packet has been sent too late (142547)
access_output_udp debug: packet has been sent too late (142547)
access_output_udp debug: packet has been sent too late (99522)
access_output_udp debug: packet has been sent too late (99522)
access_output_udp debug: packet has been sent too late (99522)
access_output_udp debug: packet has been sent too late (99522)
access_output_udp debug: packet has been sent too late (56497)
access_output_udp debug: packet has been sent too late (56497)
access_output_udp debug: packet has been sent too late (56497)
access_output_udp debug: packet has been sent too late (56497)
main error: ES_OUT_SET_(GROUP_)PCR is called too late, increasing pts_delay to 1000 ms
main error: ES_OUT_RESET_PCR called
main debug: Buffering 0%
main debug: Buffering 2%
main debug: Buffering 5%
main debug: Buffering 7%
main debug: Buffering 10%
main debug: Buffering 13%
main debug: Buffering 15%
main debug: Buffering 18%
main debug: Buffering 20%
main debug: Buffering 23%
main debug: Buffering 26%
main debug: Buffering 28%
main debug: Buffering 31%
main debug: Buffering 33%
main debug: Buffering 36%
main debug: Buffering 39%
main debug: Buffering 41%
main debug: Buffering 44%
main debug: Buffering 47%
main debug: Buffering 49%
main debug: Buffering 52%
main debug: Buffering 54%
main debug: Buffering 57%
main debug: Buffering 60%
main debug: Buffering 62%
main debug: Buffering 65%
main debug: Buffering 67%
main debug: Buffering 70%
main debug: Buffering 73%
main debug: Buffering 75%
main debug: Buffering 78%
main debug: Buffering 80%
main debug: Buffering 83%
main debug: Buffering 86%
main debug: Buffering 88%
main debug: Buffering 91%
main debug: Buffering 94%
main debug: Buffering 96%
main debug: Buffering 99%
main debug: Stream buffering done (1018 ms in 0 ms)
main debug: Decoder buffering done in 0 ms
main warning: late buffer for mux input (16123)
main warning: late buffer for mux input (16123)
main warning: late buffer for mux input (16123)
main warning: late buffer for mux input (16123)
access_output_udp debug: late packet for UDP input (4987396)
access_output_udp debug: late packet for UDP input (4940107)
access_output_udp debug: late packet for UDP input (4891111)
access_output_udp debug: late packet for UDP input (4842116)
access_output_udp debug: packet has been sent too late (4987396)
access_output_udp debug: late packet for UDP input (4987396)
access_output_udp debug: late packet for UDP input (4940107)
access_output_udp debug: late packet for UDP input (4891111)
access_output_udp debug: late packet for UDP input (4842116)
access_output_udp debug: packet has been sent too late (4940107)
access_output_udp debug: packet has been sent too late (4987396)
access_output_udp debug: packet has been sent too late (4891111)
access_output_udp debug: late packet for UDP input (4987396)
access_output_udp debug: late packet for UDP input (4940107)
access_output_udp debug: late packet for UDP input (4891111)
access_output_udp debug: late packet for UDP input (4842116)
access_output_udp debug: late packet for UDP input (4987396)
access_output_udp debug: packet has been sent too late (4940107)
access_output_udp debug: packet has been sent too late (4842116)
access_output_udp debug: packet has been sent too late (4987396)
access_output_udp debug: packet has been sent too late (4891111)
access_output_udp debug: late packet for UDP input (4940107)
access_output_udp debug: late packet for UDP input (4891111)
access_output_udp debug: late packet for UDP input (4842116)
access_output_udp debug: packet has been sent too late (4987396)
access_output_udp debug: packet has been sent too late (4940107)
access_output_udp debug: packet has been sent too late (4842116)
access_output_udp debug: packet has been sent too late (4940107)
access_output_udp debug: packet has been sent too late (4891111)
access_output_udp debug: packet has been sent too late (4891111)
access_output_udp debug: packet has been sent too late (4842116)
access_output_udp debug: late packet for UDP input (4793121)
access_output_udp debug: packet has been sent too late (4842116)
access_output_udp debug: packet has been sent too late (4793121)
access_output_udp debug: mmh, hole (5395437 > 2s) -> drop
access_output_udp debug: late packet for UDP input (4793121)
access_output_udp debug: packet has been sent too late (4793121)
access_output_udp debug: mmh, hole (5395437 > 2s) -> drop
access_output_udp debug: late packet for UDP input (4793121)
access_output_udp debug: late packet for UDP input (4793121)
access_output_udp debug: packet has been sent too late (4793121)
access_output_udp debug: mmh, hole (5395437 > 2s) -> drop
access_output_udp debug: packet has been sent too late (4793121)
access_output_udp debug: mmh, hole (5395437 > 2s) -> drop
access_output_udp debug: dropped 1 packets
access_output_udp debug: dropped 1 packets
access_output_udp debug: dropped 1 packets
access_output_udp debug: dropped 1 packets
main error: ES_OUT_SET_(GROUP_)PCR is called too late, increasing pts_delay to 5839 ms
main error: ES_OUT_RESET_PCR called
main debug: Buffering 0%
main debug: Buffering 0%
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 5%
main debug: Buffering 5%
main debug: Buffering 6%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 12%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Buffering 13%
main debug: Buffering 14%
main debug: Buffering 14%
main debug: Buffering 15%
main debug: Buffering 15%
main debug: Buffering 16%
main debug: Buffering 16%
main debug: Buffering 16%
main debug: Buffering 17%
main debug: Buffering 17%
main debug: Buffering 18%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering 19%
main debug: Buffering 20%
main debug: Buffering 20%
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 22%
main debug: Buffering 22%
main debug: Buffering 23%
main debug: Buffering 23%
main debug: Buffering 24%
main debug: Buffering 24%
main debug: Buffering 25%
main debug: Buffering 25%
main debug: Buffering 25%
main debug: Buffering 26%
main debug: Buffering 26%
main debug: Buffering 27%
main debug: Buffering 27%
main debug: Buffering 28%
main debug: Buffering 28%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering 38%
main debug: Buffering 38%
main debug: Buffering 39%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 42%
main debug: Buffering 42%
main debug: Buffering 43%
main debug: Buffering 43%
main debug: Buffering 44%
main debug: Buffering 44%
main debug: Buffering 45%
main debug: Buffering 45%
main debug: Buffering 46%
main debug: Buffering 46%
main debug: Buffering 46%
main debug: Buffering 47%
main debug: Buffering 47%
main debug: Buffering 48%
main debug: Buffering 48%
main debug: Buffering 49%
main debug: Buffering 49%
main debug: Buffering 50%
main debug: Buffering 50%
main debug: Buffering 50%
main debug: Buffering 51%
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering 52%
main debug: Buffering 53%
main debug: Buffering 53%
main debug: Buffering 54%
main debug: Buffering 54%
main debug: Buffering 55%
main debug: Buffering 55%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering 56%
main debug: Buffering 57%
main debug: Buffering 57%
main debug: Buffering 58%
main debug: Buffering 58%
main debug: Buffering 59%
main debug: Buffering 59%
main debug: Buffering 59%
main debug: Buffering 60%
main debug: Buffering 60%
main debug: Buffering 61%
main debug: Buffering 61%
main debug: Buffering 62%
main debug: Buffering 62%
main debug: Buffering 63%
main debug: Buffering 63%
main debug: Buffering 63%
main debug: Buffering 64%
main debug: Buffering 64%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: Buffering 69%
main debug: Buffering 69%
main debug: Buffering 70%
main debug: Buffering 70%
main debug: Buffering 71%
main debug: Buffering 71%
main debug: Buffering 72%
main debug: Buffering 72%
main debug: Buffering 72%
main debug: Buffering 73%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 74%
main debug: Buffering 75%
main debug: Buffering 75%
main debug: Buffering 76%
main debug: Buffering 76%
main debug: Buffering 76%
main debug: Buffering 77%
main debug: Buffering 77%
main debug: Buffering 78%
main debug: Buffering 78%
main debug: Buffering 79%
main debug: Buffering 79%
main debug: Buffering 80%
main debug: Buffering 80%
main debug: Buffering 80%
main debug: Buffering 81%
main debug: Buffering 81%
main debug: Buffering 82%
main debug: Buffering 82%
main debug: Buffering 83%
main debug: Buffering 83%
main debug: Buffering 84%
main debug: Buffering 84%
main debug: Buffering 84%
main debug: Buffering 85%
main debug: Buffering 85%
main debug: Buffering 86%
main debug: Buffering 86%
main debug: Buffering 87%
main debug: Buffering 87%
main debug: Buffering 88%
main debug: Buffering 88%
main debug: Buffering 89%
main debug: Buffering 89%
main debug: Buffering 89%
main debug: Buffering 90%
main debug: Buffering 90%
main debug: Buffering 91%
main debug: Buffering 91%
main debug: Buffering 92%
main debug: Buffering 92%
main debug: Buffering 93%
main debug: Buffering 93%
main debug: Buffering 93%
main debug: Buffering 94%
main debug: Buffering 94%
main debug: Buffering 95%
main debug: Buffering 95%
main debug: Buffering 96%
main debug: Buffering 96%
main debug: Buffering 97%
main debug: Buffering 97%
main debug: Buffering 97%
main debug: Buffering 98%
main debug: Buffering 98%
main debug: Buffering 99%
main debug: Buffering 99%
main debug: Stream buffering done (5851 ms in 11 ms)
main debug: Decoder buffering done in 0 ms
main warning: late buffer for mux input (16123)
main warning: late buffer for mux input (16123)
main warning: late buffer for mux input (16123)
main warning: late buffer for mux input (16123)
access_output_udp debug: late packet for UDP input (4413188)
access_output_udp debug: late packet for UDP input (4349774)
access_output_udp debug: packet has been sent too late (4413188)
access_output_udp debug: late packet for UDP input (4282963)
access_output_udp debug: packet has been sent too late (4349774)
access_output_udp debug: packet has been sent too late (4282963)
access_output_udp debug: late packet for UDP input (4413188)
access_output_udp debug: late packet for UDP input (4349774)
access_output_udp debug: late packet for UDP input (4282963)
access_output_udp debug: packet has been sent too late (4413188)
access_output_udp debug: late packet for UDP input (4413188)
access_output_udp debug: packet has been sent too late (4349774)
access_output_udp debug: packet has been sent too late (4282963)
access_output_udp debug: packet has been sent too late (4413188)
access_output_udp debug: late packet for UDP input (4349774)
access_output_udp debug: late packet for UDP input (4282963)
access_output_udp debug: packet has been sent too late (4349774)
access_output_udp debug: late packet for UDP input (4413188)
access_output_udp debug: packet has been sent too late (4282963)
access_output_udp debug: late packet for UDP input (4353774)
access_output_udp debug: packet has been sent too late (4417188)
access_output_udp debug: late packet for UDP input (4286963)
access_output_udp debug: packet has been sent too late (4353774)
access_output_udp debug: late packet for UDP input (4220151)
access_output_udp debug: packet has been sent too late (4286963)
access_output_udp debug: packet has been sent too late (4220151)
access_output_udp debug: mmh, hole (4830760 > 2s) -> drop
access_output_udp debug: late packet for UDP input (4220151)
access_output_udp debug: packet has been sent too late (4220151)
access_output_udp debug: mmh, hole (4830760 > 2s) -> drop
access_output_udp debug: late packet for UDP input (4220151)
access_output_udp debug: packet has been sent too late (4220151)
access_output_udp debug: mmh, hole (4830760 > 2s) -> drop
access_output_udp debug: late packet for UDP input (4220151)
access_output_udp debug: packet has been sent too late (4220151)
access_output_udp debug: mmh, hole (4830760 > 2s) -> drop
access_output_udp debug: dropped 1 packets
access_output_udp debug: dropped 1 packets
access_output_udp debug: dropped 1 packets
access_output_udp debug: dropped 1 packets

[Shai-Hulud]

mp3 playback should be a simple task for vlc. I have not had a problem with it ever. I would suspect a network issue or computer issue over a vlc issue in this circumstance. Things to look at:

You can try using Ethereal (lanshark now?) to analyze your network traffic to see if you're getting a lot of retransmission requests, errors, etc. As a simple indicator that you may be having network issues you can try opening task manager and viewing the network tab to see when transferring large files if your network speeds are all over the place rather than somewhat steady...could be an indicator, could not. Another simple test to see if packets are being dropped over your network is to ping different machines using "ping <ipaddress> -n 100" and see how many packets if any are being dropped. You can also use "ping <ipaddress> -t" for a continuous monitor. But make sure you're pinging other devices on your network, not over the internet, assuming you're streaming locally.

Although you're on GigE if the wiring is messed up or you have a defective port on your router/hub or in a nic it will adversely affect your network. TCP/IP is a reliable protocol and will ensure your data gets to its destination even in a very buggy network. Unfortunately, it's not very reliable for streaming in those circumstances. So do a little checkup on your network and don't assume because you have Gigabit ether you're good.

As for a machine issue check out cpu utilizations, disk accesses. If you're getting a lot of both, could be an issue.

Have you tried streaming video? Same thing or not?

[VLC_help]

Also, use broadcast in case all computers are on same LAN. So one dst=239.255.12.42:1234 and open 239.255.12.42:1234 on all clients.

[tcc]

mp3 playback should be a simple task for vlc. I have not had a problem with it ever. I would suspect a network issue or computer issue over a vlc issue in this circumstance. Things to look at:

You can try using Ethereal (lanshark now?) to analyze your network traffic to see if you're getting a lot of retransmission requests, errors, etc. As a simple indicator that you may be having network issues you can try opening task manager and viewing the network tab to see when transferring large files if your network speeds are all over the place rather than somewhat steady...could be an indicator, could not. Another simple test to see if packets are being dropped over your network is to ping different machines using "ping <ipaddress> -n 100" and see how many packets if any are being dropped. You can also use "ping <ipaddress> -t" for a continuous monitor. But make sure you're pinging other devices on your network, not over the internet, assuming you're streaming locally.

Although you're on GigE if the wiring is messed up or you have a defective port on your router/hub or in a nic it will adversely affect your network. TCP/IP is a reliable protocol and will ensure your data gets to its destination even in a very buggy network. Unfortunately, it's not very reliable for streaming in those circumstances. So do a little checkup on your network and don't assume because you have Gigabit ether you're good.

As for a machine issue check out cpu utilizations, disk accesses. If you're getting a lot of both, could be an issue.

Have you tried streaming video? Same thing or not?

Thanks for the good troubleshooting advice. The LAN checked out ok but an examination of the file server turned up a couple of issues that were causing file access delays. This led to VLC becoming starved for input and ultimately droppng packets.

These messages in the log always precipitated a re-buffering / dropped packets sequence.

main error: ES_OUT_SET_(GROUP_)PCR is called too late, increasing pts_delay to 300 ms
main error: ES_OUT_RESET_PCR called

So, after a bit of learning and server-reconfig, all is well now.

Regards,
Tim