If you are running version 1.8 or newer you can enable CEL (Channel Event
Logging) to get a better view of the channel events.
A common issue for terminating calls is high packet loss, you can measure the
network with some kind of probe.
Also, don?t forget the guides here:
http://www.voiptroubleshooter.com/diagnosis/index.html
/ Tobias
-----Original Message-----
From: Jeff LaCoursiere [mailto:jeff at sunfone.com]
Sent: den 21 december 2011 21:58
To: asterisk-users at lists.digium.com
Subject: [asterisk-users] Diagnosing call hangups
Hi,
I have customers complaining of random call hangups, and I am trying to
determine in each case what happened to the call. I normally run a
customer's PBX with verbose set to 3 and debug off, and looking at each case
in the "full" log (default full in logger.conf) I don't see
anything special between the call being answered and the call terminating - the
log lines look exactly the same whether the local side hung up on purpose, the
remote side hung up on purpose, or something unknown happened and the call
simply terminates (FreePBX dialplan in
place):
Examples from our lab today:
[Dec 21 14:17:31] VERBOSE[12854] logger.c: -- SIP/astnorth-00000f70
answered SIP/100-00000f6f
LOCAL SIDE HUNGUP
[Dec 21 14:17:37] VERBOSE[12854] logger.c: -- Executing
[h at macro-dialout-trunk:1] Macro("SIP/100-00000f6f",
"hangupcall|") in new stack
------
[Dec 21 14:14:44] VERBOSE[12764] logger.c: -- SIP/astnorth-00000f6c
answered SIP/100-00000f6b
REMOTE SIDE HUNGUP
[Dec 21 14:14:56] VERBOSE[12764] logger.c: -- Executing
[h at macro-dialout-trunk:1] Macro("SIP/100-00000f6b",
"hangupcall|") in new stack
-----
An example from the customer site:
[Dec 19 13:24:04] VERBOSE[13794] logger.c: -- SIP/sunfone-000052ad
answered SIP/239-000052ac
[Dec 19 13:24:04] VERBOSE[13794] logger.c: -- Packet2Packet bridging
SIP/239-000052ac and SIP/sunfone-000052ad
UNKNOWN EVENT
[Dec 19 13:24:11] VERBOSE[13794] logger.c: -- Executing
[h at macro-dialout-trunk:1] Macro("SIP/239-000052ac",
"hangupcall|") in new stack
------------------------------------
So in our lab I turned up verbose to 100 and debug to 100 and made some tests
with a local SIP phone calling out to a cell via our upstream
provider:
[Dec 21 14:19:56] VERBOSE[12912] logger.c: -- SIP/astnorth-00000f72
answered SIP/100-00000f71
[Dec 21 14:19:56] DEBUG[12912] devicestate.c: Notification of state change to be
queued on device/channel SIP/100 [Dec 21 14:19:56] DEBUG[12912] chan_sip.c: SIP
answering channel:
SIP/100-00000f71
[Dec 21 14:19:56] DEBUG[12912] rtp.c: Setting the marker bit due to a source
update [Dec 21 14:19:56] DEBUG[12912] chan_sip.c: Setting framing from config on
incoming call [Dec 21 14:19:56] DEBUG[12912] chan_sip.c: ** Our capability: 0x4
(ulaw) Video flag: True [Dec 21 14:19:56] DEBUG[12912] chan_sip.c: ** Our
prefcodec: 0x0
(nothing)
[Dec 21 14:19:56] DEBUG[12912] chan_sip.c: -- Done with adding codecs to SDP
[Dec 21 14:19:56] DEBUG[12912] chan_sip.c: Done building SDP. Settling with this
capability: 0x4 (ulaw) [Dec 21 14:19:56] DEBUG[12912] res_features.c: Removing
dialed interfaces datastore on SIP/100-00000f71 since we're bridging [Dec 21
14:19:56] DEBUG[12912] res_features.c: Removing dialed interfaces datastore on
SIP/astnorth-00000f72 since we're bridging [Dec 21 14:19:56] DEBUG[12912]
rtp.c: Setting the marker bit due to a source update [Dec 21 14:19:56]
DEBUG[12912] rtp.c: Setting the marker bit due to a source update [Dec 21
14:19:56] DEBUG[12912] rtp.c: Got RTCP report of 64 bytes
REMOTE SIDE HUNGUP
[Dec 21 14:20:01] DEBUG[12912] rtp.c: Got RTCP report of 64 bytes [Dec 21
14:20:03] DEBUG[12912] channel.c: Didn't get a frame from
channel: SIP/astnorth-00000f72
[Dec 21 14:20:03] DEBUG[12912] rtp.c: Setting the marker bit due to a source
update [Dec 21 14:20:03] DEBUG[12912] channel.c: Bridge stops bridging channels
SIP/100-00000f71 and SIP/astnorth-00000f72 [Dec 21 14:20:03] DEBUG[12912] pbx.c:
Launching 'Macro'
[Dec 21 14:20:03] VERBOSE[12912] logger.c: -- Executing
[h at macro-dialout-trunk:1] Macro("SIP/100-00000f71",
"hangupcall|") in new stack
----
[Dec 21 14:25:12] VERBOSE[13081] logger.c: -- SIP/astnorth-00000f74
answered SIP/100-00000f73
[Dec 21 14:25:12] DEBUG[13081] devicestate.c: Notification of state change to be
queued on device/channel SIP/100 [Dec 21 14:25:12] DEBUG[13081] chan_sip.c: SIP
answering channel:
SIP/100-00000f73
[Dec 21 14:25:12] DEBUG[13081] rtp.c: Setting the marker bit due to a source
update [Dec 21 14:25:12] DEBUG[13081] chan_sip.c: Setting framing from config on
incoming call [Dec 21 14:25:12] DEBUG[13081] chan_sip.c: ** Our capability: 0x4
(ulaw) Video flag: True [Dec 21 14:25:12] DEBUG[13081] chan_sip.c: ** Our
prefcodec: 0x0
(nothing)
[Dec 21 14:25:12] DEBUG[13081] chan_sip.c: -- Done with adding codecs to SDP
[Dec 21 14:25:12] DEBUG[13081] chan_sip.c: Done building SDP. Settling with this
capability: 0x4 (ulaw) [Dec 21 14:25:12] DEBUG[13081] res_features.c: Removing
dialed interfaces datastore on SIP/100-00000f73 since we're bridging [Dec 21
14:25:12] DEBUG[13081] res_features.c: Removing dialed interfaces datastore on
SIP/astnorth-00000f74 since we're bridging [Dec 21 14:25:12] DEBUG[13081]
rtp.c: Setting the marker bit due to a source update [Dec 21 14:25:12]
DEBUG[13081] rtp.c: Setting the marker bit due to a source update [Dec 21
14:25:16] DEBUG[13081] rtp.c: Got RTCP report of 64 bytes
LOCAL SIDE HUNG UP
[Dec 21 14:25:21] DEBUG[13081] rtp.c: Got RTCP report of 64 bytes [Dec 21
14:25:21] DEBUG[13081] channel.c: Didn't get a frame from
channel: SIP/100-00000f73
[Dec 21 14:25:21] DEBUG[13081] rtp.c: Setting the marker bit due to a source
update [Dec 21 14:25:21] DEBUG[13081] channel.c: Bridge stops bridging channels
SIP/100-00000f73 and SIP/astnorth-00000f74 [Dec 21 14:25:21] DEBUG[13081] pbx.c:
Launching 'Macro'
[Dec 21 14:25:21] VERBOSE[13081] logger.c: -- Executing
[h at macro-dialout-trunk:1] Macro("SIP/100-00000f73",
"hangupcall|") in new stack
-------------------------
After all of that, the question:
The difference seems to be which side reports "Didn't get a frame from
channel:". If the hangup was local, it is the local channel. If the
hangup was remote, it is the remote channel. I guess that makes sense, but is
there something returned from either "Dial" or "Answer" that
would allow me to log which side hungup without having to enable debug and plow
through a gazillion log lines to find the answer?
How do others debug random hangups for customers?
Thanks!
Jeff LaCoursiere
SunFone