What caused this dropped call?

1

With IAX logging enabled, I usually receive a HANGUP packet with cause 16. Does that ALWAYS mean that the caller hung up their phone normally, or could it mean that the call was dropped due to a technical problem?

Here’s a sample of a dropped call. I noticed that, at the end, we started receiving RTP packets but were not sending them anymore. Could this be because our upload bandwidth is too low?

[2017-12-07 09:30:43.823] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Sent RTP packet to 10.20.1.53:11982 (type 00, seq 024804, ts 243560, len 000160)
[2017-12-07 09:30:43.827] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001515, ts 498923951, len 000160)
[2017-12-07 09:30:43.846] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Sent RTP packet to 10.20.1.53:11982 (type 00, seq 024805, ts 243720, len 000160)
[2017-12-07 09:30:43.847] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001516, ts 498924111, len 000160)
[2017-12-07 09:30:43.860] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Sent RTP packet to 10.20.1.53:11982 (type 00, seq 024806, ts 243880, len 000160)
[2017-12-07 09:30:43.867] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001517, ts 498924271, len 000160)
[2017-12-07 09:30:43.887] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001518, ts 498924431, len 000160)
[2017-12-07 09:30:43.907] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001519, ts 498924591, len 000160)
[2017-12-07 09:30:43.927] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001520, ts 498924751, len 000160)
[2017-12-07 09:30:43.947] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001521, ts 498924911, len 000160)
[2017-12-07 09:30:43.967] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001522, ts 498925071, len 000160)
[2017-12-07 09:30:43.987] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001523, ts 498925231, len 000160)
[2017-12-07 09:30:44.007] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001524, ts 498925391, len 000160)
[2017-12-07 09:30:44.027] VERBOSE[135691][C-00000091] res_rtp_asterisk.c: Got RTP packet from 10.20.1.53:11982 (type 00, seq 001525, ts 498925551, len 000160)
[2017-12-07 09:30:44.036] VERBOSE[2029] chan_iax2.c: Rx-Frame Retry[ No] – OSeqno: 011 ISeqno: 017 Type: IAX Subclass: HANGUP
[2017-12-07 09:30:44.036] VERBOSE[2029] chan_iax2.c: Timestamp: 34132ms SCall: 07865 DCall: 12065 162.254.144.176:4569
[2017-12-07 09:30:44.036] VERBOSE[2029] chan_iax2.c: CAUSE CODE : 16

2

Found this on Google:
https://wiki.asterisk.org/wiki/display/AST/Hangup+Cause+Mappings

“This cause indicates that the call is being cleared because one of the users involved in the call has requested that the call be cleared. Under normal situations, the source of this cause is not the network.”

You would need to plug in to your network to see if you were dropping traffic.

3

That’s what I read too, but we are dropping about 1/3 of our calls each day, and they always end with HANGUP cause code 16, and I’m sure people aren’t intentionally hanging up. It mostly happens when someone is on hold for 10-20 seconds but sometimes happens mid-sentence.

If the Asterisk log says “Rx-Frame” does that mean it was received from the external caller, or could it mean it’s received from our internal extension that answered the call?

4

Can you turn up the verbosity/enable debug and watch for a failed call?

5

I have verbosity at 10 and enabled RTP and IAX2 debugging. That’s where I got the logs from in the first post. I never see any errors or failures during a call. When users report a dropped call, I investigate every time, and I always see that RX:HANGUP 16 packet.

Are there more debugging logs that I should turn on?

6

With the verbosity up I would have expected to see things like:
DCall: 14775 [192.168.2.11:4569]
RR_JITTER : 0
RR_LOSS : 0
RR_PKTS : 1
RR_DELAY : 40
RR_DROPPED : 0
RR_OUTOFORDER : 0

Are you able to check your network traffic and see if you are dropping any 4569 traffic? Also what version of Asterisk/FreePBX?

7

I do see some of that stuff during the call, but it didn’t happen during the short snippet I posted. The whole log of the one call is thousands of lines.

[2017-12-07 09:30:30.924] VERBOSE[2027] chan_iax2.c: Rx-Frame Retry[ No] – OSeqno: 007 ISeqno: 013 Type: IAX Subclass: PING
[2017-12-07 09:30:30.924] VERBOSE[2027] chan_iax2.c: Timestamp: 21019ms SCall: 07865 DCall: 12065 162.254.144.176:4569
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: Tx-Frame Retry[000] – OSeqno: 013 ISeqno: 008 Type: IAX Subclass: PONG
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: Timestamp: 21019ms SCall: 12065 DCall: 07865 162.254.144.176:4569
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: RR_JITTER : 0
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: RR_LOSS : 0
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: RR_PKTS : 1
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: RR_DELAY : 40
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: RR_DROPPED : 0
[2017-12-07 09:30:30.924] VERBOSE[2013] chan_iax2.c: RR_OUTOFORDER : 0

FreePBX 14.0.1.20
Asterisk 14.7.3
I don’t see any blocking of port 4569. Most of our calls work, so this seems to be an intermittent problem.