cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1537
Views
0
Helpful
2
Replies

WebEx Codec Plus looses Audio randomly during a WebEx CMR meeting

sapan0007
Level 1
Level 1

Software version:ce 9.5.0 fb56c25334b 2018-09-13

Registration: On-prem Expressway Core Cluster

One of our codecs randomly looses audio for remote webex attendees for a minute while being connected to a WebEx Meeting using "Call My Video System". This happened again today twice during the same WebEx meeting. I am sharing the logged events from the codec when this issue happened. I am not sure what these log entries on the event log indicate. But wanted to know experts opinion that is this something which could be responsible for audio drops during the webex meeting.

 

2019-08-14T09:39:20.964-07:00 Olympus appl[1724]: MainEvents I: InputAudioChannelChanged(p=42,gid=521) msctrlId=583 channels=2 encryption=AES-128 muted=False protocol=Off
2019-08-14T09:39:22.149-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: no incoming data
2019-08-14T09:39:28.840-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: no incoming video
2019-08-14T09:39:36.229-07:00 Olympus eventlog[1724]: audplayout: Severe timegap, delta rx time 17370 ms, delta timestamp 20 ms, RxTime 2335179360, lastRxTime 2334345600, sr 48000
2019-08-14T09:39:36.230-07:00 Olympus appl[1724]: AdaptationResilience I: [wqos] CBandwidthEvaluator::Adjustment, state = BANDWIDTH_UP|BANDWIDTH_REACH_MAX, bandwidth = 6000000, inputRate = 0, receiveRate = 73560, qdelay = 0, rtt = 0, lossRatio = 0 this=0xeedacbb8
2019-08-14T09:39:36.234-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: incoming stream: std H.264NIL, res 1280x720, sar 1x1
2019-08-14T09:39:36.247-07:00 Olympus I/video ( 1517): Dec-0: input queue too large, clearing
2019-08-14T09:39:36.247-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: Decode Err: [0]:Still experiencing (1): intra request
2019-08-14T09:39:36.247-07:00 Olympus I/video ( 1517): Dec-0: input queue too large, clearing
2019-08-14T09:39:36.247-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: Decode Err: [1]:Still experiencing (1): output but missing ref frame
2019-08-14T09:39:36.252-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: Decode Err: [2]:Still experiencing (1): 1
2019-08-14T09:39:36.254-07:00 Olympus I/video ( 1517): Dec-0: input queue too large, clearing
2019-08-14T09:39:36.255-07:00 Olympus appl[1724]: MainEvents I: InputAudioChannelChanged(p=42,gid=521) msctrlId=583 channels=1 encryption=AES-128 muted=False protocol=Opus

 

 

2 Replies 2

sapan0007
Level 1
Level 1
Logs from second occurrence when remote attendees lost audio:

2019-08-14T10:45:02.336-07:00 Olympus appl[1724]: MainEvents I: InputAudioChannelChanged(p=42,gid=521) msctrlId=583 channels=2 encryption=AES-128 muted=False protocol=Off
2019-08-14T10:45:03.550-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: no incoming data
2019-08-14T10:45:10.240-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: no incoming video
2019-08-14T10:45:20.132-07:00 Olympus eventlog[1724]: audplayout: Severe timegap, delta rx time 19900 ms, delta timestamp 20 ms, RxTime 2524486080, lastRxTime 2523530880, sr 48000
2019-08-14T10:45:20.133-07:00 Olympus appl[1724]: AdaptationResilience I: [wqos] CBandwidthEvaluator::Adjustment, state = BANDWIDTH_HOLD, bandwidth = 6000000, inputRate = 0, receiveRate = 113544, qdelay = 0, rtt = 0, lossRatio = 0 this=0xeedacbb8
2019-08-14T10:45:20.134-07:00 Olympus I/video ( 1517): Dec-0: input queue too large, clearing
2019-08-14T10:45:20.134-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: Decode Err: [0]:Still experiencing (1): intra request
2019-08-14T10:45:20.135-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: Decode Err: [1]:Still experiencing (6): output but missing ref frame
2019-08-14T10:45:20.138-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: incoming stream: std H.264NIL, res 1280x720, sar 1x1
2019-08-14T10:45:20.140-07:00 Olympus I/video ( 1517): DEC_FSM-0 I: Decode Err: [2]:Still experiencing (6): 1
2019-08-14T10:45:20.144-07:00 Olympus eventlog[1724]: audplayout: high receiverate stream 0, last cycle 1952.00, this ts 2689682636, last ts 2688745676, samplerate 48000, packets (seq, count) (976, 1)
2019-08-14T10:45:20.146-07:00 Olympus appl[1724]: MainEvents I: InputAudioChannelChanged(p=42,gid=521) msctrlId=583 channels=1 encryption=AES-128 muted=False protocol=Opus
2019-08-14T10:45:25.316-07:00 Olympus appl[1724]: MainEvents I: ActiveSpeakerReported(c=31,p=42)
2019-08-14T10:45:25.316-07:00 Olympus appl[1724]: MainEvents I: ActiveSpeakerIndication(c=31,p=42)
2019-08-14T10:45:25.420-07:00 Olympus appl[1724]: AdaptationResilience I: [wqos] CBandwidthEvaluator::Adjustment, state = BANDWIDTH_UP|BANDWIDTH_REACH_MAX, bandwidth = 6000000, inputRate = 0, receiveRate = 2984968, qdelay = 0, rtt = 0, lossRatio = 0 this=0xeedacbb8
2019-08-14T10:45:29.536-07:00 Olympus appl[1724]: MainEvents I: ActiveSpeakerReported(c=31,p=1)
2019-08-14T10:45:29.536-07:00 Olympus appl[1724]: MainEvents I: ActiveSpeakerIndication(c=31,p=1)

Now that I looked deeper, I see it on all the codec happening at the same time. This cannot be a coincidence. See two other examples below:

 

2019-08-14T10:45:04.451-07:00 Force-Field appl[1791]: MainEvents I: InputAudioChannelChanged(p=1033,gid=11699) msctrlId=20440 channels=2 encryption=AES-128 muted=False protocol=Off
2019-08-14T10:45:05.669-07:00 Force-Field I/video   ( 1512): DEC_FSM-0 I: no incoming data
2019-08-14T10:45:12.366-07:00 Force-Field I/video   ( 1512): DEC_FSM-0 I: no incoming video
2019-08-14T10:45:12.668-07:00 Force-Field appl[1791]: MainEvents I: LayoutUpdated(p=1) outputNo=1 og=114
2019-08-14T10:45:12.669-07:00 Force-Field appl[1791]: MainEvents I: LayoutUpdated ...frame[GUI] gui p=1 src=1 ig=-1 CSISceneId=0 type=- placeholder=0 avatar=0 reso=-1/-1 crop=0/0/1000/1000 x=0 y=0 w=10000 h=10000 l=0 b=0 m=0 letterbox fcref=0 boardSessionId=0
2019-08-14T10:45:13.051-07:00 Force-Field I/hwcomposer( 1429): void nvhwc_display::update_layer_clip(int, int): layer_clip is identical, not changing
2019-08-14T10:45:20.003-07:00 Force-Field I/hwcomposer([1590]: Last message '1429): void nvhwc_di' repeated 14 times, suppressed by syslog-ng on Force-Field
2019-08-14T10:45:20.003-07:00 Force-Field appl[1791]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2591592360, ts = 2591610065 this=0xee1342dc
2019-08-14T10:45:20.003-07:00 Force-Field appl[1791]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2591592360, ts = 2591610065 this=0xef0c7334
2019-08-14T10:45:20.003-07:00 Force-Field eventlog[1791]: audplayout: Severe timegap, delta rx time 17640 ms, delta timestamp 20 ms, RxTime 1476996224, lastRxTime 1476149504, sr 48000
2019-08-14T10:45:20.003-07:00 Force-Field appl[1791]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2591592370, ts = 2591610065 this=0xee5b0d84
2019-08-14T10:45:20.003-07:00 Force-Field appl[1791]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2591592370, ts = 2591610065 this=0xee90001c
2019-08-14T10:45:20.008-07:00 Force-Field I/video   ( 1512): DEC_FSM-0 I: incoming stream: std H.264NIL, res 1280x720, sar 1x1
2019-08-14T10:45:20.018-07:00 Force-Field I/video   ( 1512): Dec-0: input queue too large, clearing
2019-08-14T10:45:20.018-07:00 Force-Field I/video   ( 1512): DEC_FSM-0 I: Decode Err: [0]:intra request
2019-08-14T10:45:20.018-07:00 Force-Field I/video   ( 1512): DEC_FSM-0 I: Decode Err: [1]:output but missing ref frame
2019-08-14T10:45:20.021-07:00 Force-Field I/video   ( 1512): DEC_FSM-0 I: Decode Err: [2]:(null)
2019-08-14T10:45:20.027-07:00 Force-Field I/video   ( 1512): Dec-0: input queue too large, clearing
2019-08-14T10:45:20.051-07:00 Force-Field I/video[1590]: Last message '  ( 1512): Dec-0: in' repeated 2 times, suppressed by syslog-ng on Force-Field
2019-08-14T10:45:20.051-07:00 Force-Field appl[1791]: MainEvents I: InputAudioChannelChanged(p=1033,gid=11699) msctrlId=20440 channels=1 encryption=AES-128 muted=False protocol=Opus
2019-08-14T10:45:20.061-07:00 Force-Field I/video   ( 1512): Dec-0: input queue too large, clearing


2019-08-14T10:45:02.360-07:00 Multiverse appl[1800]: MainEvents I: InputAudioChannelChanged(p=143,gid=1556) msctrlId=2524 channels=2 encryption=AES-128 muted=False protocol=Off
2019-08-14T10:45:03.522-07:00 Multiverse I/video   ( 1538): DEC_FSM-1 I: no incoming data
2019-08-14T10:45:03.588-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: no incoming data
2019-08-14T10:45:08.160-07:00 Multiverse appl[1800]: MainEvents I: ActiveSpeakerReported(c=113,p=1)
2019-08-14T10:45:08.160-07:00 Multiverse appl[1800]: MainEvents I: ActiveSpeakerIndication(c=113,p=1)
2019-08-14T10:45:10.219-07:00 Multiverse I/video   ( 1538): DEC_FSM-1 I: no incoming video
2019-08-14T10:45:10.219-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: no incoming video
2019-08-14T10:45:10.522-07:00 Multiverse appl[1800]: MainEvents I: LayoutUpdated(p=1) outputNo=1 og=114
2019-08-14T10:45:10.522-07:00 Multiverse appl[1800]: MainEvents I: LayoutUpdated ...frame[1.0.1.143.0.p.1] presentation p=143 src=0 ig=1560 CSISceneId=0 type=- placeholder=0 avatar=0 reso=0/0 crop=0/0/1000/1000 x=0 y=0 w=10000 h=10000 l=1 b=0 m=0 letterbox fcref=0 boardSessionId=-1
2019-08-14T10:45:10.522-07:00 Multiverse appl[1800]: MainEvents I: LayoutUpdated ...frame[GUI] gui p=1 src=1 ig=-1 CSISceneId=0 type=- placeholder=0 avatar=0 reso=-1/-1 crop=0/0/1000/1000 x=0 y=0 w=10000 h=10000 l=0 b=0 m=0 letterbox fcref=0 boardSessionId=0
2019-08-14T10:45:20.127-07:00 Multiverse appl[1800]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2923543780, ts = 2923563669 this=0xeef6377c
2019-08-14T10:45:20.128-07:00 Multiverse appl[1800]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2923543780, ts = 2923563669 this=0xee73765c
2019-08-14T10:45:20.128-07:00 Multiverse appl[1800]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2923543739, ts = 2923563670 this=0xef092e54
2019-08-14T10:45:20.128-07:00 Multiverse appl[1800]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2923543739, ts = 2923563670 this=0xefb0c0ec
2019-08-14T10:45:20.128-07:00 Multiverse eventlog[1800]: audplayout: Severe timegap, delta rx time 19900 ms, delta timestamp 20 ms, RxTime 805179296, lastRxTime 804224096, sr 48000
2019-08-14T10:45:20.129-07:00 Multiverse appl[1800]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2923543739, ts = 2923563671 this=0xef0e158c
2019-08-14T10:45:20.129-07:00 Multiverse appl[1800]: AdaptationResilience W:  [wqos] CQosNetworkPacketLossRatio::Notify, time rollback or skip, record_ts = 2923543739, ts = 2923563671 this=0xeea698ec
2019-08-14T10:45:20.138-07:00 Multiverse I/video   ( 1538): DEC_FSM-1 I: incoming stream: std H.264NIL, res 1920x1080, sar 1x1
2019-08-14T10:45:20.145-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: incoming stream: std H.264NIL, res 1280x720, sar 1x1
2019-08-14T10:45:20.148-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: Decode Err: [0]:Still experiencing (1): intra request
2019-08-14T10:45:20.155-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: Decode Err: [4]:Still experiencing (2): 8
2019-08-14T10:45:20.159-07:00 Multiverse eventlog[1800]: audplayout: high receiverate stream 0, last cycle 1972.00, this ts 215391733, last ts 214445173, samplerate 48000, packets (seq, count) (986, 1)
2019-08-14T10:45:20.163-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: Decode Err: [1]:Still experiencing (5): output but missing ref frame
2019-08-14T10:45:20.165-07:00 Multiverse I/video   ( 1538): DEC_FSM-0 I: Decode Err: [2]:Still experiencing (5): 1
2019-08-14T10:45:20.160-07:00 Multiverse appl[1800]: MainEvents I: InputAudioChannelChanged(p=143,gid=1556) msctrlId=2524 channels=1 encryption=AES-128 muted=False protocol=Opus
2019-08-14T10:45:20.204-07:00 Multiverse I/video   ( 1538): DEC_FSM-1 I: Decode Err: [0]:Still experiencing (1): intra request
2019-08-14T10:45:20.205-07:00 Multiverse I/video   ( 1538): DEC_FSM-1 I: Decode Err: [2]:Still experiencing (1): output but missing ref frame
2019-08-14T10:45:20.213-07:00 Multiverse I/video   ( 1538): DEC_FSM-1 I: Decode Err: [3]:Still experiencing (1): 1
2019-08-14T10:45:20.342-07:00 Multiverse appl[1800]: MainEvents I: LayoutUpdated(p=1) outputNo=1 og=114
2019-08-14T10:45:20.342-07:00 Multiverse appl[1800]: MainEvents I: LayoutUpdated ...frame[1.0.1.143.0.p.1] presentation p=143 src=0 ig=1560 CSISceneId=0 type=- placeholder=0 avatar=0 reso=1920/1080 crop=0/0/1000/1000 x=0 y=0 w=10000 h=10000 l=1 b=0 m=0 stretch fcref=0 boardSessionId=-1