[Linphone-developers] Linphone OSx video for msx264 VGA is too slow

[fess]

Hello,

I run Linphone 3.5.99.0

 ffmpeg-devel @20130205_0+gpl2 

I compiled and built iLBC and msx264.

build Linphone:

# ./autogen.sh
# LDFLAGS+="-L/usr/local/lib -lcurl" LIBS+=-I/local/include ./configure
--prefix=/opt/linphone --with-readline=/opt/linphone --disable-x11
--with-srtp=/opt/linphone --with-gsm=/opt/linphone --disable-zrtp
--enable-relativeprefix --enable-console_ui=no
# make && make install && make bundle


However, when I run VGA, with plugin msx264 I see very big delay, even for
self-view !!!! (4-6 sec)

...
Video MSTicker: We are late of 4202 miliseconds.
...

For msx263 or msx264 CIF, all work fine.

The same version runs on PC without any problems too.

Please help me to spread light on that  problem,

where is the issue, ffmpeg, msx264, iLBC or Linphone?



This is a log I have so far:



message: cb_snd123456xx (id=8)
message: eXosip: Reseting timer to 10s before waking up!
warning: Video MSTicker: We are late of 115 miliseconds.
warning: Video MSTicker: We are late of 241 miliseconds.
message: A SPS is being sent.
message: A PPS is being sent.
warning: Video MSTicker: We are late of 278 miliseconds.
warning: Video MSTicker: We are late of 332 miliseconds.
message: ms_quality_indicator_update_local(): no packet received since last
call
message: audio_stream_iterate(): local statistics available
        Local's current jitter buffer size:0.000000 ms
warning: Video MSTicker: We are late of 432 miliseconds.
warning: Video MSTicker: We are late of 572 miliseconds.
warning: Video MSTicker: We are late of 709 miliseconds.
warning: Video MSTicker: We are late of 849 miliseconds.
message: bandwidth usage: audio=[d=0.0,u=82.0] video=[d=0.0,u=356.7]
kbit/sec
message: Thread processing load: audio=2.125003 video=704.317993
warning: Video MSTicker: We are late of 997 miliseconds.
warning: Video MSTicker: We are late of 1140 miliseconds.
warning: Video MSTicker: We are late of 1289 miliseconds.
warning: Video MSTicker: We are late of 1448 miliseconds.
warning: Video MSTicker: We are late of 1600 miliseconds.
warning: Video MSTicker: We are late of 1748 miliseconds.
message: bandwidth usage: audio=[d=0.0,u=81.2] video=[d=0.0,u=321.2]
kbit/sec
message: Thread processing load: audio=2.000675 video=1124.223022
warning: Video MSTicker: We are late of 1900 miliseconds.
warning: Video MSTicker: We are late of 2040 miliseconds.
warning: Video MSTicker: We are late of 2184 miliseconds.
warning: Video MSTicker: We are late of 2325 miliseconds.
warning: Video MSTicker: We are late of 2467 miliseconds.
warning: Video MSTicker: We are late of 2608 miliseconds.
message: ms_quality_indicator_update_local(): no packet received since last
call
message: audio_stream_iterate(): local statistics available
        Local's current jitter buffer size:0.000000 ms
warning: Video MSTicker: We are late of 2752 miliseconds.
message: bandwidth usage: audio=[d=0.0,u=81.5] video=[d=0.0,u=333.7]
kbit/sec
message: Thread processing load: audio=1.934875 video=1336.241333
warning: Video MSTicker: We are late of 2899 miliseconds.
warning: Video MSTicker: We are late of 3049 miliseconds.
warning: Video MSTicker: We are late of 3203 miliseconds.
warning: Video MSTicker: We are late of 3352 miliseconds.
warning: Video MSTicker: We are late of 3499 miliseconds.
message: Received message: 
INFO sip:address@hidden SIP/2.0
Via: SIP/2.0/UDP
64.71.138.170:5060;rport;branch=z9hG4bKPj919c492e-2fa5-4003-98c3-743367e9ff44
Max-Forwards: 70
From: <sip:address@hidden>;tag=fc1e9236-1e38-4702-8a52-1e4615a2ad30
To: <sip:address@hidden>;tag=428238745
Call-ID: 128473832
CSeq: 2977 INFO
Contact: <sip:address@hidden:5060>
User-Agent: EMC1000
Content-Type: application/media_control+xml
Content-Length:   176

<?xml version="1.0" encoding="utf-8" ?>
<media_control>
<vc_primitive>
<to_encoder>
<picture_fast_update>
</picture_fast_update>
</to_encoder>
</vc_primitive>
</media_control>

message: Message received from: 64.71.138.170:5060
message: Message received from: 64.71.138.170:5060
message: MESSAGE REC. CALLID:128473832
message: Message received from: 64.71.138.170:5060
message: This is a request
message: allocating transaction ressource 9 128473832
message: allocating NIST context
message: cb_rcvunkrequest (id=9)
message: cb_rcv? (id=9)
message: eXosip: Reseting timer to 10s before waking up!
message: eXosip: Reseting timer to 10s before waking up!
warning: Video MSTicker: We are late of 3646 miliseconds.
message: linphone process event get a message 18

message: EXOSIP_CALL_MESSAGE_NEW
message: Receiving VFU request !
message: DNS resolution with 64.71.138.170:5060
message: getaddrinfo returned the following addresses:
message: 64.71.138.170 port 5060
message: Message sent: (to dest=64.71.138.170:5060)
SIP/2.0 200 OK
Via: SIP/2.0/UDP
64.71.138.170:5060;rport=5060;branch=z9hG4bKPj919c492e-2fa5-4003-98c3-743367e9ff44
From: <sip:address@hidden>;tag=fc1e9236-1e38-4702-8a52-1e4615a2ad30
To: <sip:address@hidden>;tag=428238745
Call-ID: 128473832
CSeq: 2977 INFO
Contact: <sip:address@hidden:5060>
User-Agent: Orion-O/1.0.0.8 (eXosip2/3.3.0)
Content-Length: 0


message: cb_snd123456xx (id=9)
message: eXosip: Reseting timer to 10s before waking up!
message: bandwidth usage: audio=[d=0.0,u=81.4] video=[d=0.0,u=305.5]
kbit/sec
message: Thread processing load: audio=1.951840 video=1454.387817
warning: Video MSTicker: We are late of 3790 miliseconds.
warning: Video MSTicker: We are late of 3938 miliseconds.
message: A SPS is being sent.
message: A PPS is being sent.
warning: Video MSTicker: We are late of 3984 miliseconds.
warning: Video MSTicker: We are late of 4006 miliseconds.
warning: Video MSTicker: We are late of 4043 miliseconds.
warning: Video MSTicker: We are late of 4107 miliseconds.
message: Receiving first SPS
message: Receiving first PPS
message: Getting yuv picture of 640x480
warning: Video MSTicker: We are late of 4202 miliseconds.
message: resize opengles_display (104 x 104, gl initialized:1)
message: allocate_gl_textures: allocated new textures[0] (1024 x 512)

message: resize opengles_display (114 x 110, gl initialized:1)
message: resize opengles_display (130 x 122, gl initialized:1)
message: resize opengles_display (150 x 136, gl initialized:1)
message: resize opengles_display (178 x 154, gl initialized:1)
message: resize opengles_display (206 x 176, gl initialized:1)
warning: Video MSTicker: We are late of 4312 miliseconds.
message: resize opengles_display (242 x 200, gl initialized:1)
message: resize opengles_display (280 x 226, gl initialized:1)
message: resize opengles_display (318 x 254, gl initialized:1)
message: resize opengles_display (360 x 284, gl initialized:1)
message: resize opengles_display (400 x 312, gl initialized:1)
message: resize opengles_display (442 x 340, gl initialized:1)
message: resize opengles_display (480 x 368, gl initialized:1)
message: resize opengles_display (516 x 392, gl initialized:1)
warning: Video MSTicker: We are late of 4426 miliseconds.
message: resize opengles_display (550 x 416, gl initialized:1)
message: resize opengles_display (578 x 436, gl initialized:1)
message: resize opengles_display (602 x 454, gl initialized:1)
message: resize opengles_display (620 x 466, gl initialized:1)
message: resize opengles_display (634 x 476, gl initialized:1)
message: resize opengles_display (640 x 480, gl initialized:1)
message: event_cb called 1074069760
warning: In linphonecall.c: video_stream_event_cb
message: First video frame decoded successfully
warning: Video MSTicker: We are late of 4542 miliseconds.
message: bandwidth usage: audio=[d=0.0,u=81.4] video=[d=312.0,u=486.7]
kbit/sec
message: Thread processing load: audio=2.145340 video=1166.343140
warning: Video MSTicker: We are late of 4671 miliseconds.
warning: Video MSTicker: We are late of 4800 miliseconds.
warning: Video MSTicker: We are late of 4946 miliseconds.
message: ms_quality_indicator_update_local(): no packet received since last
call
message: audio_stream_iterate(): local statistics available
        Local's current jitter buffer size:0.000000 ms
warning: Video MSTicker: We are late of 5088 miliseconds.
warning: Video MSTicker: We are late of 5253 miliseconds.
warning: Video MSTicker: We are late of 5408 miliseconds.
message: bandwidth usage: audio=[d=0.0,u=80.7] video=[d=684.8,u=265.8]
kbit/sec
message: Thread processing load: audio=2.071345 video=1351.914795
warning: Video MSTicker: We are late of 5569 miliseconds.
warning: Video MSTicker: We are late of 5723 miliseconds.
warning: Video MSTicker: We are late of 5882 miliseconds.
warning: Video MSTicker: We are late of 6035 miliseconds.
warning: Video MSTicker: We are late of 6187 miliseconds.
warning: Video MSTicker: We are late of 6340 miliseconds.
message: bandwidth usage: audio=[d=0.0,u=80.0] video=[d=636.0,u=297.5]
kbit/sec
message: Thread processing load: audio=1.966088 video=1491.089966
warning: Video MSTicker: We are late of 6492 miliseconds.
warning: Video MSTicker: We are late of 6647 miliseconds.
warning: Video MSTicker: We are late of 6799 miliseconds.
warning: Video MSTicker: We are late of 6955 miliseconds.
message: Fess :: linphone_gtk_terminate_call
message: allocating transaction ressource 10 128473832
message: allocating NICT context
message: DNS resolution with 64.71.138.170:5060
message: getaddrinfo returned the following addresses:
message: 64.71.138.170 port 5060
message: Message sent: (to dest=64.71.138.170:5060)
BYE sip:address@hidden:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.16:5060;rport;branch=z9hG4bK959685103
From: <sip:address@hidden>;tag=428238745
To: <sip:address@hidden>;tag=fc1e9236-1e38-4702-8a52-1e4615a2ad30
Call-ID: 128473832
CSeq: 21 BYE
Contact: <sip:address@hidden:5060>
Max-Forwards: 70
User-Agent: Orion-O/1.0.0.8 (eXosip2/3.3.0)
Content-Length: 0


message: cb_sndbye (id=10)
warning: keep alive: 3
message: eXosip: Keep Alive sent on UDP!
message: eXosip: timer sec:0 usec:100000!
warning: Video MSTicker: We are late of 7109 miliseconds.
message: Filter MSRtpRecv is not scheduled; nothing to do.
message: ===========================================================
message:              AUDIO SESSION'S RTP STATISTICS                
message: -----------------------------------------------------------
message: sent                                           485 packets
message:                                              83420 bytes  
message: received                                         0 packets
message:                                                  0 bytes  
message: incoming delivered to the app                    0 bytes  
message: lost                                             0 packets
message: received too late                                0 packets
message: bad formatted                                    0 packets
message: discarded (queue overflow)                       0 packets
message: ===========================================================
message: ms_filter_unlink:
MSAuRead:0x7fa5ac603ab0,0-->MSResample:0x7fa5ac604360,0
message: ms_filter_unlink:
MSResample:0x7fa5ac604360,0-->MSSpeexEC:0x7fa5ac603320,1
message: ms_filter_unlink:
MSSpeexEC:0x7fa5ac603320,1-->MSVolume:0x7fa5ac604000,0
message: ms_filter_unlink:
MSVolume:0x7fa5ac604000,0-->MSTee:0x7fa5ac604b50,0
message: ms_filter_unlink:
MSTee:0x7fa5ac604b50,0-->MSUlawEnc:0x7fa5ac603de0,0
message: ms_filter_unlink:
MSUlawEnc:0x7fa5ac603de0,0-->MSRtpSend:0x7fa5ac6031d0,0
message: ms_filter_unlink:
MSRtpRecv:0x7fa5ac603930,0-->MSUlawDec:0x7fa5ac603f10,0
message: ms_filter_unlink:
MSUlawDec:0x7fa5ac603f10,0-->MSGenericPLC:0x7fa5ac605760,0
message: ms_filter_unlink:
MSGenericPLC:0x7fa5ac605760,0-->MSDtmfGen:0x7fa5ac603a20,0
message: ms_filter_unlink:
MSDtmfGen:0x7fa5ac603a20,0-->MSVolume:0x7fa5ac6041d0,0
message: ms_filter_unlink:
MSVolume:0x7fa5ac6041d0,0-->MSTee:0x7fa5ac604a10,0
message: ms_filter_unlink:
MSTee:0x7fa5ac604a10,0-->MSEqualizer:0x7fa5ac604d70,0
message: ms_filter_unlink:
MSEqualizer:0x7fa5ac604d70,0-->MSSpeexEC:0x7fa5ac603320,0
message: ms_filter_unlink:
MSSpeexEC:0x7fa5ac603320,0-->MSResample:0x7fa5ac604530,0
message: ms_filter_unlink:
MSResample:0x7fa5ac604530,0-->MSAuWrite:0x7fa5ac603c40,0
message: ms_filter_unlink:
MSTee:0x7fa5ac604b50,1-->MSAudioMixer:0x7fa5ac604800,0
message: ms_filter_unlink:
MSTee:0x7fa5ac604a10,1-->MSAudioMixer:0x7fa5ac604800,1
message: ms_filter_unlink:
MSAudioMixer:0x7fa5ac604800,0-->MSFileRec:0x7fa5ac604700,0
message: Audio MSTicker thread exiting
message: ===========================================================
message:                   FILTER USAGE STATISTICS                  
message: Name                Count     Time/tick (ms)      CPU Usage
message: -----------------------------------------------------------
message: MSX264Enc           58        130.763             96.4071   
message: MSResample          1672      0.0600054           1.25446   
message: MSSpeexEC           836       0.102075            1.06762   
message: MSH264Dec           20        2.682               0.703802  
message: MSRtpSend           1238      0.0143075           0.221517  
message: MSRtpRecv           1238      0.0121646           0.18834   
message: MSAudioMixer        974       0.00244308          0.0297656 
message: MSOSXGLDisplay      58        0.0344576           0.0254044 
message: MSV4m               265       0.00753008          0.0250296 
message: MSUlawEnc           836       0.00211231          0.022093  
message: MSAuRead            974       0.00114974          0.0140081 
message: MSFileRec           974       0.000819487         0.00998434
message: MSTee               915       0.000746725         0.00854729
message: MSVolume            836       0.000752688         0.00787251
message: MSDtmfGen           974       0.000460513         0.00561072
message: MSGenericPLC        974       0.000349744         0.00426115
message: MSAuWrite           836       0.000329749         0.00344891
message: MSSizeConv          59        0.000883333         0.00066229
message: MSPixConv           59        0.0004              0.000299905
message: MSJpegWriter        20        0.000714286         0.000187441
message: MSEqualizer         0         0                   0         
message: MSUlawDec           0         0                   0         
message: MSFilePlayer        0         0                   0         
message: MSVoidSink          0         0                   0         
message: ===========================================================
message: eXosip: timer sec:0 usec:100000!
warning: Video MSTicker: We are late of 7254 miliseconds.
message: v4m video device closed.
message: Filter MSRtpRecv is not scheduled; nothing to do.
message: ===========================================================
message:              VIDEO SESSION'S RTP STATISTICS                
message: -----------------------------------------------------------
message: sent                                           264 packets
message:                                             309925 bytes  
message: received                                       291 packets
message:                                             253459 bytes  
message: incoming delivered to the app               165511 bytes  
message: lost                                             0 packets
message: received too late                                0 packets
message: bad formatted                                    0 packets
message: discarded (queue overflow)                       0 packets
message: ===========================================================
message: ms_filter_unlink:
MSV4m:0x7fa5ac08b0b0,0-->MSPixConv:0x7fa5ac08bf30,0
message: ms_filter_unlink:
MSPixConv:0x7fa5ac08bf30,0-->MSSizeConv:0x7fa5ac08e7c0,0
message: ms_filter_unlink:
MSSizeConv:0x7fa5ac08e7c0,0-->MSTee:0x7fa5ac08b230,0
message: ms_filter_unlink:
MSTee:0x7fa5ac08b230,0-->MSX264Enc:0x7fa5ac0b0b70,0
message: ms_filter_unlink:
MSX264Enc:0x7fa5ac0b0b70,0-->MSRtpSend:0x7fa5ac6024c0,0
message: ms_filter_unlink:
MSRtpRecv:0x7fa5ac095580,0-->MSH264Dec:0x7fa5ac093b20,0
message: ms_filter_unlink:
MSH264Dec:0x7fa5ac093b20,0-->MSTee:0x7fa5ac087e60,0
message: ms_filter_unlink:
MSTee:0x7fa5ac087e60,1-->MSJpegWriter:0x7fa5ac0a3eb0,0
message: ms_filter_unlink:
MSTee:0x7fa5ac087e60,0-->MSOSXGLDisplay:0x7fa5ac09fdf0,0
message: ms_filter_unlink:
MSTee:0x7fa5ac08b230,1-->MSOSXGLDisplay:0x7fa5ac09fdf0,1


Thank you very much!

Maxim Shoustin,



--
View this message in context: 
http://nongnu.13855.n7.nabble.com/Linphone-OSx-video-for-msx264-VGA-is-too-slow-tp172170.html
Sent from the linphone-developers mailing list archive at Nabble.com.