Problems with h264 streaming with B-Frames

[Gastonuy]

Hi
I'm trying to stream h.264 videos. I'm enconding them with Canopus ProCoder 3 and then I'm sending them with VLC and receiving them wit VLC.
The problem occurs when the GOP has B-frames, the video on the receiver frezzes, when I encode it without B-Frames it works like a charm. I tried to change many parameters but the result is the same. I'm using the GUI for the streamer.
Any idea why this could be happening? Is there any known issues with H.264 streaming?
Thanks!

[giangy11]

are you streaming video on internet or locale lan?

[VLC_help]

What error message VLC shows in Tools -> Messages... (set Verbosity to 2) when freeze occurs?

[Gastonuy]

Well, on the receiver I get the following messages:

Code: Select all

main debug: creating demux: access='udp' demux='' path='@:1234' main debug: looking for demux module: 51 candidates main debug: using demux module "ts" main debug: TIMER module_Need() : 4.000 ms - Total 4.000 ms / 1 intvls (Avg 4.000 ms) main debug: looking for a subtitle file in C:\Archivos de programa\VideoLAN\VLC\ ts debug: DEMUX_SET_GROUP 0 00000000 access_udp warning: unimplemented query in control main debug: `udp://@:1234' successfully opened qt4 debug: New Event: type 1103 ts debug: PATCallBack called qt4 debug: Updating the stream status: 3 ts debug: new PAT ts_id=1453 version=16 current_next=1 ts debug: * number=1 pid=66 ts debug: PMTCallBack called ts debug: new PMT program number=1 version=4 pid_pcr=68 ts debug: * es pid=68 type=27 fcc=h264 main debug: selecting program id=1 main debug: looking for decoder module: 34 candidates avcodec debug: libavcodec already initialized qt4 debug: New Event: type 1108 avcodec debug: ffmpeg codec (H264 - MPEG-4 AVC (part 10)) started main debug: using decoder module "avcodec" main debug: TIMER module_Need() : 4.000 ms - Total 4.000 ms / 1 intvls (Avg 4.000 ms) main debug: looking for packetizer module: 18 candidates main debug: using packetizer module "packetizer_h264" main debug: TIMER module_Need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms) main debug: thread 5608 (decoder) created at priority 0 (input/decoder.c:217) main debug: thread started main debug: control type=1 packetizer_h264 debug: found NAL_SPS (sps_id=0) packetizer_h264 debug: found NAL_PPS (pps_id=0 sps_id=0) main debug: no usable vout present, spawning one main debug: window size: 720x528 main debug: looking for video output module: 6 candidates vout_directx debug: creating DirectXEventThread main debug: waiting for thread initialization main debug: thread started vout_directx debug: DirectXCreateWindow main debug: looking for vout window module: 2 candidates qt4 debug: waiting for interface... qt4 debug: requesting window... qt4 debug: Video was requested -1, -1 qt4 debug: Video is resizing to: 720 528 qt4 debug: Qt FS: Attaching Vout qt4 debug: Qt: Changing Fullscreen Mode main debug: using vout window module "qt4" main debug: TIMER module_Need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms) qt4 debug: Updating the geometry vout_directx debug: created video sub-window main debug: thread 5724 (Vout Events Thread) created at priority 0 (directx.c:281) vout_directx debug: Vout EventThread running vout_directx debug: DirectXInitDDraw vout_directx debug: directx-device: vout_directx debug: DirectXEnumCallback: Controlador de pantalla primaria, display vout_directx debug: DirectXEnumCallback: Mobile Intel(R) 945GM/GU Express Chipset Family, \\.\DISPLAY1 vout_directx debug: selecting Mobile Intel(R) 945GM/GU Express Chipset Family, \\.\DISPLAY1 vout_directx debug: screen dimensions (0x0,1280x800) vout_directx debug: DirectDraw Capabilities: overlay=1 yuvoverlay=1 can_deinterlace_overlay=1 colorkey=1 stretch=1 bltfourcc=1 vout_directx debug: End DirectXInitDDraw vout_directx debug: DirectXCreateDisplay vout_directx debug: DirectXCreateClipper vout_directx debug: disabling screen saver main debug: using video output module "vout_directx" main debug: TIMER module_Need() : 132.000 ms - Total 132.000 ms / 1 intvls (Avg 132.000 ms) main debug: waiting for thread initialization main debug: thread started vout_directx debug: NewPictureVec overlay:yes chroma:YV12 vout_directx debug: YUV overlay created successfully vout_directx debug: End NewPictureVec (succeeded) main debug: got 1 direct buffer(s) main debug: picture in 720x480 (0,0,720x480), chroma I420, ar 58909:43200, sar 10:11 main debug: picture user 720x480 (0,0,720x480), chroma I420, ar 58909:43200, sar 10:11 main debug: picture out 720x480 (0,0,720x480), chroma I420, ar 58909:43200, sar 10:11 main debug: direct render, mapping render pictures 0-6 to system pictures 1-7 main debug: thread 5664 (video output) created at priority 1 (video_output/video_output.c:502) qt4 debug: New Event: type 1109 avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) main debug: looking for text renderer module: 2 candidates main debug: thread 5828 (fontlist builder) created at priority 0 (freetype.c:477) freetype debug: using fontsize: 30 main debug: using text renderer module "freetype" main debug: TIMER module_Need() : 2.000 ms - Total 2.000 ms / 1 intvls (Avg 2.000 ms) freetype debug: using fontsize: 30 main debug: thread started freetype debug: Building font database... freetype debug: Finished building font database. freetype debug: Took 0 seconds main debug: thread ended main debug: looking for video blending module: 1 candidate blend debug: chroma: YUVA -> I420 main debug: using video blending module "blend" main debug: TIMER module_Need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0) avcodec warning: Missing reference picture (h264@0D7464A0)

And on the transmiter:

Code: Select all

main debug: starting new item main debug: processing request item Streaming node Lista de reproducción skip 0 main debug: resyncing on Streaming main debug: Streaming is at 0 main debug: creating new input thread main debug: Creating an input for 'Streaming' main debug: waiting for thread initialization main debug: thread started main debug: thread 5472 (input) created at priority 1 (input/input.c:370) qt4 debug: Updating the stream status: 3 main debug: stream=`duplicate' main debug: looking for sout stream module: 1 candidate stream_out_duplicate debug: creating 'duplicate' stream_out_duplicate debug: * adding `std{access=udp,dst=10.135.85.7:1234}' main debug: stream=`std' main debug: looking for sout stream module: 1 candidate main debug: set config option: sout-standard-access to udp main debug: set config option: sout-standard-dst to 10.135.85.7:1234 stream_out_standard debug: creating `udp/(null)://10.135.85.7:1234' stream_out_standard debug: extension is 7:1234 stream_out_standard debug: extension -> mux=(null) stream_out_standard debug: using `udp/ts://10.135.85.7:1234' main debug: looking for sout access module: 1 candidate main debug: net: connecting to [10.135.85.7]:1234 access_output_udp debug: source: 10.135.85.7 port 2590 access_output_udp debug: destination: 10.135.85.7 port 1234 main debug: thread 5452 (sout write thread) created at priority 15 (udp.c:255) main debug: using sout access module "access_output_udp" main debug: TIMER module_Need() : 6.000 ms - Total 6.000 ms / 1 intvls (Avg 6.000 ms) main debug: thread started stream_out_standard debug: access opened main debug: looking for sout mux module: 1 candidate mux_ts debug: shaping=200000 pcr=70000 dts_delay=400000 main debug: using sout mux module "mux_ts" main debug: TIMER module_Need() : 9.000 ms - Total 9.000 ms / 1 intvls (Avg 9.000 ms) main debug: muxer support adding stream at any time stream_out_standard debug: mux opened main debug: using sout stream module "stream_out_standard" main debug: TIMER module_Need() : 26.000 ms - Total 26.000 ms / 1 intvls (Avg 26.000 ms) main debug: using sout stream module "stream_out_duplicate" main debug: TIMER module_Need() : 26.000 ms - Total 26.000 ms / 1 intvls (Avg 26.000 ms) main debug: `C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' gives access `' demux `' path `C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' main debug: creating demux: access='' demux='' path='C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' main debug: looking for access_demux module: 1 candidate main debug: TIMER module_Need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms) main debug: creating access '' path='C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' qt4 debug: New Event: type 1103 qt4 debug: Updating the stream status: 1 main debug: looking for access module: 5 candidates vcd debug: trying .cue file: C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.cue vcd debug: could not find .cue file access_file debug: opening file `C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' main debug: using access module "access_file" main debug: TIMER module_Need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms) main debug: Using AStream*Stream main debug: pre-buffering... main debug: received first data for our buffer qt4 debug: New Event: type 1103 qt4 debug: Updating the stream status: 2 main debug: pre-buffering done 1408981 bytes in 0s - 275136 kbytes/s main debug: creating demux: access='' demux='' path='C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' main debug: looking for demux module: 59 candidates h264 warning: h264 module discarded (no startcode) main debug: using demux module "ts" main debug: TIMER module_Need() : 3.000 ms - Total 3.000 ms / 1 intvls (Avg 3.000 ms) main debug: looking for a subtitle file in C:\Documents and Settings\gguridi\Mis documentos\ ts debug: DEMUX_SET_GROUP 0 00000000 main debug: starting in async mode main debug: `C:\Documents and Settings\gguridi\Mis documentos\src16_ref__525_480_H264_GOP33.h264' successfully opened ts debug: pid[481] unknown ts debug: PATCallBack called ts debug: new PAT ts_id=0 version=0 current_next=1 ts debug: * number=1 pid=480 ts debug: PMTCallBack called qt4 debug: New Event: type 1103 qt4 debug: Updating the stream status: 3 ts debug: new PMT program number=1 version=0 pid_pcr=481 ts debug: * es pid=2064 type=27 fcc=h264 main debug: selecting program id=1 main debug: looking for packetizer module: 18 candidates main debug: using packetizer module "packetizer_h264" main debug: TIMER module_Need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms) main debug: stream out mode -> no decoder thread main debug: control type=1 qt4 debug: New Event: type 1108 packetizer_h264 debug: found NAL_SPS (sps_id=0) packetizer_h264 debug: found NAL_PPS (pps_id=0 sps_id=0) main debug: adding a new sout input (sout_input:02610C88) stream_out_duplicate debug: duplicated a new stream codec=h264 (es=2064 group=1) main debug: adding a new input mux_ts debug: adding input codec=h264 pid=68 mux_ts debug: new PCR PID is 68 stream_out_duplicate debug: - added for output 0 main debug: switching to sync mode mux_ts warning: packet with too strange dts (dts=13240925511,old=13240992244,pcr=13240992244) mux_ts warning: packet with too strange dts (dts=13241125711,old=13241192444,pcr=13241192444) mux_ts warning: packet with too strange dts (dts=13241325911,old=13241392644,pcr=13241392644) mux_ts warning: packet with too strange dts (dts=13241526111,old=13241592844,pcr=13241592844) mux_ts warning: packet with too strange dts (dts=13241726311,old=13241793044,pcr=13241793044) mux_ts warning: packet with too strange dts (dts=13241926511,old=13241993244,pcr=13241993244) mux_ts warning: packet with too strange dts (dts=13242126711,old=13242193444,pcr=13242193444) mux_ts warning: packet with too strange dts (dts=13242326911,old=13242393644,pcr=13242393644) mux_ts warning: packet with too strange dts (dts=13242527111,old=13242593844,pcr=13242593844) mux_ts warning: packet with too strange dts (dts=13242727311,old=13242794044,pcr=13242794044) mux_ts warning: packet with too strange dts (dts=13243060978,old=13243127711,pcr=13243127711) mux_ts warning: packet with too strange dts (dts=13243261178,old=13243327911,pcr=13243327911) mux_ts warning: packet with too strange dts (dts=13243461378,old=13243528111,pcr=13243528111) mux_ts warning: packet with too strange dts (dts=13243661578,old=13243728311,pcr=13243728311) mux_ts warning: packet with too strange dts (dts=13243861778,old=13243928511,pcr=13243928511) access_output_udp debug: mmh, packets in the past (91113) access_output_udp debug: packet has been sent too late (91347) access_output_udp debug: packet has been sent too late (77740) access_output_udp debug: packet has been sent too late (64133) access_output_udp debug: packet has been sent too late (50526) access_output_udp debug: packet has been sent too late (36919) access_output_udp debug: packet has been sent too late (23312) access_output_udp debug: mmh, packets in the past (87216) access_output_udp debug: packet has been sent too late (87815) access_output_udp debug: packet has been sent too late (73564) access_output_udp debug: packet has been sent too late (59314) access_output_udp debug: packet has been sent too late (45063) access_output_udp debug: packet has been sent too late (30813) mux_ts warning: packet with too strange dts (dts=13244061978,old=13244128711,pcr=13244128711) access_output_udp debug: mmh, packets in the past (86284) access_output_udp debug: packet has been sent too late (86087) access_output_udp debug: packet has been sent too late (69863) access_output_udp debug: packet has been sent too late (53640) access_output_udp debug: packet has been sent too late (37416) access_output_udp debug: packet has been sent too late (21192) mux_ts warning: packet with too strange dts (dts=13244262178,old=13244328911,pcr=13244328911) access_output_udp debug: mmh, packets in the past (84216) access_output_udp debug: packet has been sent too late (83275) access_output_udp debug: packet has been sent too late (66127) access_output_udp debug: packet has been sent too late (48980) access_output_udp debug: packet has been sent too late (31833) mux_ts warning: packet with too strange dts (dts=13244462378,old=13244529111,pcr=13244529111) access_output_udp debug: mmh, packets in the past (85653) ... ... ... ... ... ... access_output_udp debug: packet has been sent too late (31907) access_output_udp debug: mmh, packets in the past (88891) access_output_udp debug: packet has been sent too late (88770) access_output_udp debug: packet has been sent too late (77431) access_output_udp debug: packet has been sent too late (66092) access_output_udp debug: packet has been sent too late (54752) access_output_udp debug: packet has been sent too late (43413) access_output_udp debug: packet has been sent too late (32074) access_output_udp debug: packet has been sent too late (20734) mux_ts warning: packet with too strange dts (dts=13249300544,old=13249367278,pcr=13249367278) access_output_udp debug: mmh, packets in the past (89631) access_output_udp debug: packet has been sent too late (89919) access_output_udp debug: packet has been sent too late (78123) access_output_udp debug: packet has been sent too late (66328) access_output_udp debug: packet has been sent too late (54532) access_output_udp debug: packet has been sent too late (42736) access_output_udp debug: packet has been sent too late (30940) access_output_udp debug: packet has been sent too late (20144) ts debug: eof ? main debug: EOF reached main debug: finished input main debug: dying input qt4 debug: Updating the stream status: 8 main debug: dying input ts debug: pid list: ts debug: - pid[0] seen ts debug: - pid[480] seen ts debug: - pid[481] seen main debug: removing module "packetizer_h264" main debug: killing decoder fourcc `h264', 0 PES in FIFO main debug: removing a sout input (sout_input:02610C88) mux_ts debug: removing input pid=68 mux_ts debug: new PCR PID is 8191 main debug: dying input main warning: no more input streams for this mux main debug: Program doesn't contain anymore ES ts debug: - pid[2064] seen ts debug: - pid[8191] seen main debug: removing module "ts" main debug: removing module "access_file" main debug: thread ended access_output_udp debug: mmh, packets in the past (59952) access_output_udp debug: packet has been sent too late (60363) access_output_udp debug: packet has been sent too late (55591) access_output_udp debug: packet has been sent too late (50819) access_output_udp debug: packet has been sent too late (46048) access_output_udp debug: packet has been sent too late (41276) access_output_udp debug: packet has been sent too late (36504) access_output_udp debug: packet has been sent too late (31732) access_output_udp debug: packet has been sent too late (27961) access_output_udp debug: packet has been sent too late (23189) main debug: dead input main debug: thread times: real 0m14.359375s, kernel 0m0.093750s, user 0m0.187500s main debug: thread 5472 joined (playlist/engine.c:244) main debug: TIMER input launching for 'Streaming' : 48.000 ms - Total 48.000 ms / 1 intvls (Avg 48.000 ms) main debug: destroying chain... (name=duplicate) stream_out_duplicate debug: closing a duplication main debug: destroying chain... (name=std) main debug: removing module "mux_ts" main debug: thread ended main debug: thread times: real 0m14.406250s, kernel 0m0.000000s, user 0m0.000000s main debug: thread 5452 joined (udp.c:294) access_output_udp debug: UDP access output closed main debug: removing module "access_output_udp" main debug: removing module "stream_out_standard" main debug: destroying chain done main debug: removing module "stream_out_duplicate" main debug: destroying chain done main debug: starting new item main debug: changing item without a request (current 0/1) main debug: nothing to play

Any idea of what is going on??
Thanks

[VLC_help]

VLC doesn't send the video correctly. Could you try 1.0.0 test builds?

[Gastonuy]

It didn't work on 1.0.0, the video plays just like in 0.98, do you want me to post the messages log?
Do you think this can be fixed by selecting some other streaming options or encoding the video differently?
Thanks

[VLC_help]

I assume different encoding settings would fix this.

[Gastonuy]

Do you know what is the problem exactly? I would like to know why is VLC sending the video incorrectly.
Thanks

[VLC_help]

access_output_udp debug: packet has been sent too late (31833)
mux_ts warning: packet with too strange dts (dts=13244462378,old=13244529111,pcr=13244529111)

Would indicate that there are some errors at muxing. I am not sure if they are caused by muxer or is the data fed to muxer against the specs.