[Freeswitch-users] Videocall recording results in high CPU

Anthony Minessale anthony.minessale at gmail.com
Fri Dec 4 21:44:48 MSK 2015 

{vencspd=fast,vprofile=baseline}/path/to/file.mp4

You can try medium or slow for speed too.

That's the best you can hope for. video needs resources.....

On Fri, Dec 4, 2015 at 12:23 PM, SamyGo <govoiper at gmail.com> wrote:

> Hello everyone,
> I'm using latest FS version 1.7 for recording video calls. Video calls
> work very well, but every time I start recording the calls to mp4 the CPU
> jumps to about 100%. That also results in call being paused(video freezes
> and audio disappears) for few seconds and resume.
>
> The recorded file upon playback starts good for first few seconds but then
> drops alot of frames and finally gets stuck..
>
>
> freeswitch at internal> version
> FreeSWITCH Version 1.7.0+git~20151202T210853Z~c021d22ea6~64bit (git
> c021d22 2015-12-02 21:08:53Z 64bit)
>
> root at FreeSwitch:~# lsb_release -a
> Distributor ID: Debian
> Description:    Debian GNU/Linux 8.1 (jessie)
> Release:        8.1
> Codename:       jessie
>
> The Hardware specs are bit low, its in Amazon cloud
>
> Dual-Core 2.50GHz, 4GB RAM.
>
> I'll increase H/W specs and see if it helps, if there are any suggestions
> on getting this done nicely.
>
> Thanks,
> Sammy
>
>
>
> *--- LOGS When uuid_record is executed ---*
> 2015-12-04 18:16:13.623235 [DEBUG] avformat.c:1473 sample rate: 8000,
> channels: 2
> 2015-12-04 18:16:13.623235 [DEBUG] avformat.c:1573 use video codec: [28]
> h264 (H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10)
> 2015-12-04 18:16:13.623235 [NOTICE] avformat.c:437 sample_rate: 8000
> nb_samples: 1024
> Output #0, mp4, to '/tmp/newabc.mp4':
>     Stream #0.0
> : Audio: libvo_aacenc, 8000 Hz, stereo, s16, 131 kb/s
> 2015-12-04 18:16:13.623235 [INFO] avformat.c:1597 Opening File
> [/tmp/newabc.mp4] 8000hz  with VIDEO
> 2015-12-04 18:16:13.633261 [DEBUG] switch_core_media_bug.c:828 Attaching
> BUG to sofia/external/868599
> 2015-12-04 18:16:13.653256 [DEBUG] switch_core_io.c:448 Setting BUG Codec
> PCMU:0
> 2015-12-04 18:16:13.653256 [DEBUG] switch_ivr_async.c:1483 No silence
> detection configured; assuming start of speech
> 2015-12-04 18:16:13.723299 [DEBUG] avcodec.c:1044 picture size changed
> from 352x288 to 640x480, reinitializing encoder
> frame I:1     Avg QP:10.00  size:  1049
> mb I  I16..4: 100.0%  0.0%  0.0%
> coded y,uvDC,uvAC intra: 0.0% 0.0% 0.0%
> i16 v,h,dc,p: 94%  0%  6%  0%
> i8c dc,h,v,p: 100%  0%  0%  0%
> kb/s:755.28
> using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
> profile Constrained Baseline, level 4.1
> using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
> profile Constrained Baseline, level 4.1
> 264 - core 142 r2431 a5831aa - H.264/MPEG-4 AVC codec - Copyleft 2003-2014
> - http://www.videolan.org/x264.html - options: cabac=0 ref=3
> deblock=1:0:0 analyse=0x1:0x111 me=hex subme=7 psy=1 psy_rd=1.00:0.00
> mixed_ref=1 me_range=16 chroma_me=1 trellis=1 8x8dct=0 cqm=0 deadzone=21,11
> fast_pskip=1 chroma_qp_offset=-2 threads=2 lookahead_threads=1
> sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0
> constrained_intra=0 bframes=0 weightp=0 keyint=60 keyint_min=6 scenecut=40
> intra_refresh=0 rc_lookahead=40 rc=abr mbtree=1 bitrate=1981 ratetol=1.0
> qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
> 2015-12-04 18:16:13.743264 [INFO] avformat.c:1949 use video codec
> implementation Video: libx264, yuv420p, 1280x720, q=-1--1, 1981 kb/s
> 2015-12-04 18:16:13.743264 [DEBUG] avcodec.c:1044 picture size changed
> from 352x288 to 1280x720, reinitializing encoder
> frame I:1     Avg QP:10.00  size:  1049
> mb I  I16..4: 100.0%  0.0%  0.0%
> coded y,uvDC,uvAC intra: 0.0% 0.0% 0.0%
> i16 v,h,dc,p: 94%  0%  6%  0%
> i8c dc,h,v,p: 100%  0%  0%  0%
> kb/s:755.28
> using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
> profile Constrained Baseline, level 4.1
> 2015-12-04 18:16:13.743264 [NOTICE] avformat.c:518 video thread start
> 2015-12-04 18:16:13.983266 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:16.043257 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:18.421558 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 0 VER 0 LEN 4
> 2015-12-04 18:16:18.421558 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:20.513261 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:22.533260 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:24.623259 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:26.433258 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 0 VER 0 LEN 4
> 2015-12-04 18:16:26.653258 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:29.003219 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:31.013259 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:33.763260 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:34.953259 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 0 VER 0 LEN 4
> 2015-12-04 18:16:35.803260 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:37.773264 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:39.823257 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:42.003268 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:44.053263 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:46.053261 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> concealing 203 DC, 203 AC, 203 MV errors
> 2015-12-04 18:16:48.273264 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 0 VER 0 LEN 4
> 2015-12-04 18:16:48.803258 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> concealing 259 DC, 259 AC, 259 MV errors
> 2015-12-04 18:16:51.013257 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:53.223264 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> concealing 147 DC, 147 AC, 147 MV errors
> 2015-12-04 18:16:55.483258 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> concealing 198 DC, 198 AC, 198 MV errors
> concealing 602 DC, 602 AC, 602 MV errors
> 2015-12-04 18:16:59.603257 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 192 VER 2 LEN 8
> 2015-12-04 18:16:59.663254 [WARNING] switch_rtp.c:5951 INVALID RTCP PACKET
> TYPE 0 VER 0 LEN 4
> concealing 300 DC, 300 AC, 300 MV errors
> 2015-12-04 18:17:04.143260 [NOTICE] sofia.c:952 Hangup sofia/internal/
> 868499 at 52.70.5.23 [CS_EXECUTE] [NORMAL_CLEARING]
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:705 sofia/internal/
> 868499 at 52.70.5.23 ending bridge by request from read function
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:719 Ending video
> thread.
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:767 Ending video
> thread.
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:699 sofia/internal/
> 868499 at 52.70.5.23 ending bridge by request from write function
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:719 Ending video
> thread.
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:767 Ending video
> thread.
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:212
> sofia/external/868599 video thread ended.
> 2015-12-04 18:17:04.143260 [DEBUG] switch_ivr_bridge.c:212 sofia/internal/
> 868499 at 52.70.5.23 video thread ended.
> 2015-12-04 18:17:04.153216 [DEBUG] switch_core_media.c:5167 sofia/internal/
> 868499 at 52.70.5.23 Video thread ended
> 2015-12-04 18:17:04.163261 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD
> DONE [sofia/internal/868499 at 52.70.5.23]
> 2015-12-04 18:17:04.163261 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD
> DONE [sofia/external/868599]
> 2015-12-04 18:17:04.163261 [NOTICE] switch_ivr_bridge.c:881 Hangup
> sofia/external/868599 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
> 2015-12-04 18:17:04.163261 [DEBUG] switch_core_state_machine.c:542
> (sofia/external/868599) State EXCHANGE_MEDIA going to sleep
> 2015-12-04 18:17:04.163261 [DEBUG] switch_core_state_machine.c:473
> (sofia/external/868599) Running State Change CS_HANGUP
> 2015-12-04 18:17:04.163261 [DEBUG] switch_ivr_async.c:1305 Stop recording
> file /tmp/newabc.mp4
> 2015-12-04 18:17:04.163261 [DEBUG] switch_core_media.c:5167
> sofia/external/868599 Video thread ended
> 2015-12-04 18:17:04.173260 [DEBUG] switch_ivr_bridge.c:1689
> sofia/external/868599 skip receive message [UNBRIDGE] (channel is hungup
> already)
> 2015-12-04 18:17:04.173260 [DEBUG] switch_ivr_bridge.c:1692 sofia/internal/
> 868499 at 52.70.5.23 skip receive message [UNBRIDGE] (channel is hungup
> already)
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_session.c:2796
> sofia/internal/868499 at 52.70.5.23 skip receive message
> [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:539
> (sofia/internal/868499 at 52.70.5.23) State EXECUTE going to sleep
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:473
> (sofia/internal/868499 at 52.70.5.23) Running State Change CS_HANGUP
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:739
> (sofia/internal/868499 at 52.70.5.23) Callstate Change ACTIVE -> HANGUP
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:741
> (sofia/internal/868499 at 52.70.5.23) State HANGUP
> 2015-12-04 18:17:04.173260 [DEBUG] mod_sofia.c:431 Channel sofia/internal/
> 868499 at 52.70.5.23 hanging up, cause: NORMAL_CLEARING
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/868499 at 52.70.5.23 Standard HANGUP, cause: NORMAL_CLEARING
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:741
> (sofia/internal/868499 at 52.70.5.23) State HANGUP going to sleep
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:508
> (sofia/internal/868499 at 52.70.5.23) State Change CS_HANGUP -> CS_REPORTING
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:473
> (sofia/internal/868499 at 52.70.5.23) Running State Change CS_REPORTING
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:827
> (sofia/internal/868499 at 52.70.5.23) State REPORTING
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:104
> sofia/internal/868499 at 52.70.5.23 Standard REPORTING, cause:
> NORMAL_CLEARING
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:827
> (sofia/internal/868499 at 52.70.5.23) State REPORTING going to sleep
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:499
> (sofia/internal/868499 at 52.70.5.23) State Change CS_REPORTING -> CS_DESTROY
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_session.c:1646 Session 5
> (sofia/internal/868499 at 52.70.5.23) Locked, Waiting on external entities
> 2015-12-04 18:17:04.173260 [NOTICE] switch_core_session.c:1664 Session 5
> (sofia/internal/868499 at 52.70.5.23) Ended
> 2015-12-04 18:17:04.173260 [NOTICE] switch_core_session.c:1668 Close
> Channel sofia/internal/868499 at 52.70.5.23 [CS_DESTROY]
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:630
> (sofia/internal/868499 at 52.70.5.23) Running State Change CS_DESTROY
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:640
> (sofia/internal/868499 at 52.70.5.23) State DESTROY
> 2015-12-04 18:17:04.173260 [DEBUG] mod_sofia.c:341 sofia/internal/
> 868499 at 52.70.5.23 SOFIA DESTROY
> frame I:50    Avg QP:11.50  size: 99188
> frame P:1320  Avg QP:12.79  size:  9817
> mb I  I16..4: 32.3%  0.0% 67.7%
> mb P  I16..4:  1.8%  0.0%  2.3%  P16..4: 21.0%  3.5%  1.8%  0.0%  0.0%
>  skip:69.6%
> coded y,uvDC,uvAC intra: 66.2% 73.8% 61.1% inter: 8.1% 14.0% 4.7%
> i16 v,h,dc,p: 44% 23% 16% 16%
> i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 32% 35% 10%  3%  4%  3%  5%  4%  4%
> i8c dc,h,v,p: 37% 32% 20% 11%
> kb/s:9416.81
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:111
> sofia/internal/868499 at 52.70.5.23 Standard DESTROY
> 2015-12-04 18:17:04.173260 [DEBUG] switch_core_state_machine.c:640
> (sofia/internal/868499 at 52.70.5.23) State DESTROY going to sleep
> 2015-12-04 18:17:04.213268 [NOTICE] avformat.c:624 video thread done
> frame I:12    Avg QP:13.27  size: 89070
> frame P:681   Avg QP:11.76  size: 16819
> mb I  I16..4: 36.9%  0.0% 63.1%
> mb P  I16..4:  2.7%  0.0%  4.9%  P16..4: 20.0%  3.0%  1.8%  0.0%  0.0%
>  skip:67.5%
> final ratefactor: 15.09
> coded y,uvDC,uvAC intra: 68.6% 72.9% 63.8% inter: 8.6% 14.6% 6.1%
> i16 v,h,dc,p: 47% 23% 17% 12%
> i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 34% 35%  9%  3%  4%  3%  4%  4%  4%
> i8c dc,h,v,p: 39% 32% 18% 12%
> ref P L0: 90.9%  5.9%  3.2%
> kb/s:2046.12
> 2015-12-04 18:17:04.243259 [DEBUG] switch_ivr_async.c:1366 Channel is hung
> up
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_media_bug.c:1118 Removing
> BUG from sofia/external/868599
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:739
> (sofia/external/868599) Callstate Change ACTIVE -> HANGUP
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:741
> (sofia/external/868599) State HANGUP
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_media.c:10542
> sofia/external/868599 skip receive message [VIDEO_REFRESH_REQ] (channel is
> hungup already)
> 2015-12-04 18:17:04.243259 [DEBUG] mod_sofia.c:425 sofia/external/868599
> Overriding SIP cause 480 with 200 from the other leg
> 2015-12-04 18:17:04.243259 [DEBUG] mod_sofia.c:431 Channel
> sofia/external/868599 hanging up, cause: NORMAL_CLEARING
> 2015-12-04 18:17:04.243259 [DEBUG] mod_sofia.c:484 Sending BYE to
> sofia/external/868599
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:60
> sofia/external/868599 Standard HANGUP, cause: NORMAL_CLEARING
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:741
> (sofia/external/868599) State HANGUP going to sleep
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:508
> (sofia/external/868599) State Change CS_HANGUP -> CS_REPORTING
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:473
> (sofia/external/868599) Running State Change CS_REPORTING
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:827
> (sofia/external/868599) State REPORTING
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:104
> sofia/external/868599 Standard REPORTING, cause: NORMAL_CLEARING
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:827
> (sofia/external/868599) State REPORTING going to sleep
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:499
> (sofia/external/868599) State Change CS_REPORTING -> CS_DESTROY
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_session.c:1646 Session 6
> (sofia/external/868599) Locked, Waiting on external entities
> 2015-12-04 18:17:04.243259 [NOTICE] switch_core_session.c:1664 Session 6
> (sofia/external/868599) Ended
> 2015-12-04 18:17:04.243259 [NOTICE] switch_core_session.c:1668 Close
> Channel sofia/external/868599 [CS_DESTROY]
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:630
> (sofia/external/868599) Running State Change CS_DESTROY
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:640
> (sofia/external/868599) State DESTROY
> 2015-12-04 18:17:04.243259 [DEBUG] mod_sofia.c:341 sofia/external/868599
> SOFIA DESTROY
> frame I:45    Avg QP:12.50  size: 45087
> frame P:823   Avg QP:13.81  size: 11066
> mb I  I16..4: 18.3%  0.0% 81.7%
> mb P  I16..4:  6.4%  0.0% 10.7%  P16..4: 41.3% 12.4%  5.3%  0.0%  0.0%
>  skip:23.9%
> coded y,uvDC,uvAC intra: 82.3% 76.7% 61.8% inter: 28.1% 33.2% 6.8%
> i16 v,h,dc,p: 31% 33% 19% 17%
> i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 28% 38% 14%  3%  3%  4%  3%  3%  4%
> i8c dc,h,v,p: 41% 35% 18%  5%
> kb/s:9237.67
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:111
> sofia/external/868599 Standard DESTROY
> 2015-12-04 18:17:04.243259 [DEBUG] switch_core_state_machine.c:640
> (sofia/external/868599) State DESTROY going to sleep
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>



-- 
Anthony Minessale II       ♬ @anthmfs  ♬ @FreeSWITCH  ♬

☞ http://freeswitch.org/  ☞ http://cluecon.com/  ☞
http://twitter.com/FreeSWITCH
☞ irc.freenode.net #freeswitch ☞ *http://freeswitch.org/g+
<http://freeswitch.org/g+>*

ClueCon Weekly Development Call
☎ sip:888 at conference.freeswitch.org  ☎ +19193869900

https://www.youtube.com/watch?v=9XXgW34t40s
https://www.youtube.com/watch?v=NLaDpGQuZDA
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20151204/85f4ad69/attachment-0001.html

Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list