[Freeswitch-users] Videocall recording results in high CPU

SamyGo govoiper at gmail.com
Fri Dec 4 21:23:49 MSK 2015


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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20151204/1d053b61/attachment-0001.html 


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