[Freeswitch-users] Wrong hangup cause (NO_ANSWER) while answered session

Mon Aug 23 08:08:35 PDT 2010

I have setup freeswitch by using git and followed the instructions on the
wiki page. How can I retrieve the exact git version?

There is no override of the hangup cause in our code. The algorithm is very
simple; we call the originate function with the playback action and use a
wav file as argument. Hangup is done automatically by FreeSWITCH, after eof
of the wav file is reached. Or the other part hangs up before the file ends.

We dont traced the communication but in other hand, the sip codes are traced
out into the log file (183-->180-->200=call established). This show to me,
that there is no problem with the SIP transactions. Please assume, that SIP
messages are OK.

What else could be happen?

2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable
string 0 = [sip_from_uri=sip:xxxx at xxxxx]
2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable
string 1 = [ignore_early_media=true]
2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable
string 2 = [sip_cid_type=none]
2010-08-17 22:40:51.087402 [DEBUG] switch_ivr_originate.c:1979 variable
string 3 = [originate_timeout=40]
2010-08-17 22:41:09.904378 [NOTICE] switch_channel.c:779 New Channel
sofia/internal/9055599XXXXX [9e4b396e-3d99-445f-a2e8-
227e99f3f0ef]
2010-08-17 22:41:12.641362 [DEBUG] mod_sofia.c:3892
(sofia/internal/9055599XXXXX) State Change CS_NEW -> CS_INIT
2010-08-17 22:41:12.641362 [DEBUG] switch_core_session.c:1039 Send signal
sofia/internal/9055599XXXXX [BREAK]
2010-08-17 22:41:12.641362 [DEBUG] switch_core_session.c:454
sofia/internal/9055599XXXXX set UUID=9dc8a739-f439-4815-981a-347b7a90a1a8
2010-08-17 22:41:12.642441 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/9055599XXXXX) Running State Change CS_INIT
2010-08-17 22:41:12.642441 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/9055599XXXXX) State INIT
2010-08-17 22:41:12.642441 [DEBUG] mod_sofia.c:83
sofia/internal/9055599XXXXX SOFIA INIT
2010-08-17 22:41:12.643399 [DEBUG] mod_sofia.c:119
(sofia/internal/9055599XXXXX) State Change CS_INIT -> CS_ROUTING
2010-08-17 22:41:12.643399 [DEBUG] switch_core_session.c:1039 Send signal
sofia/internal/9055599XXXXX [BREAK]
2010-08-17 22:41:12.643399 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/9055599XXXXX) State INIT going to sleep
2010-08-17 22:41:12.643399 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/9055599XXXXX) Running State Change CS_ROUTING
2010-08-17 22:41:12.644456 [DEBUG] switch_channel.c:1512
(sofia/internal/9055599XXXXX) Callstate Change DOWN -> RINGING
2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/9055599XXXXX) State ROUTING
2010-08-17 22:41:12.644456 [DEBUG] mod_sofia.c:142
sofia/internal/9055599XXXXX SOFIA ROUTING
2010-08-17 22:41:12.644456 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/9055599XXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2010-08-17 22:41:12.644456 [DEBUG] switch_core_session.c:1039 Send signal
sofia/internal/9055599XXXXX [BREAK]
2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/9055599XXXXX) State ROUTING going to sleep
2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/9055599XXXXX) Running State Change CS_CONSUME_MEDIA
2010-08-17 22:41:12.644456 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/9055599XXXXX) State CONSUME_MEDIA
2010-08-17 22:41:12.645373 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/9055599XXXXX) State CONSUME_MEDIA going to sleep
2010-08-17 22:41:42.806367 [DEBUG] sofia.c:4318 Channel
sofia/internal/9055599XXXXX entering state [calling][0]
2010-08-17 22:41:42.890442 [INFO] sofia.c:662 sofia/internal/9055599XXXXX
Update Callee ID to "9055599XXXXX" <9055599XXXXX>
2010-08-17 22:41:42.894355 [DEBUG] sofia.c:4318 Channel
sofia/internal/9055599XXXXX entering state [proceeding][183]
2010-08-17 22:41:42.894355 [NOTICE] sofia.c:4390 Ring-Ready
sofia/internal/9055599XXXXX!
2010-08-17 22:41:42.895440 [DEBUG] sofia.c:4318 Channel
sofia/internal/9055599XXXXX entering state [proceeding][183]
2010-08-17 22:41:42.895440 [DEBUG] sofia.c:4329 Remote SDP:
2010-08-17 22:41:42.895440 [DEBUG] sofia_glue.c:2444 Set Codec
sofia/internal/9055599XXXXX PCMA/8000 20 ms 160 samples
2010-08-17 22:41:42.896357 [DEBUG] sofia_glue.c:3937 Set 2833 dtmf send
payload to 101
2010-08-17 22:41:42.896357 [DEBUG] sofia_glue.c:2684 AUDIO RTP
[sofia/internal/9055599XXXXX] 10.100.224.10 port 31416 -> 10.100.199.19 port
18620 codec: 8 ms: 20
2010-08-17 22:41:42.896357 [DEBUG] switch_rtp.c:1413 Starting timer [soft]
160 bytes per 20ms
2010-08-17 22:41:42.897431 [DEBUG] sofia_glue.c:2894 Set 2833 dtmf send
payload to 101
2010-08-17 22:41:42.897431 [DEBUG] sofia_glue.c:2899 Set 2833 dtmf receive
payload to 101
2010-08-17 22:41:42.897431 [NOTICE] sofia_glue.c:3292 Pre-Answer
sofia/internal/9055599XXXXX!
2010-08-17 22:41:42.897431 [DEBUG] switch_channel.c:2397
(sofia/internal/9055599XXXXX) Callstate Change RINGING -> EARLY
 2010-08-17 22:41:42.916461 [DEBUG] sofia.c:4313 Channel
sofia/internal/9055599XXXXX skipping state [proceeding][180]
2010-08-17 22:41:43.434412 [DEBUG] sofia.c:4318 Channel
sofia/internal/9055599XXXXX entering state [completing][200]
2010-08-17 22:41:43.434412 [DEBUG] sofia.c:4326 Duplicate SDP
2010-08-17 22:41:52.000488 [DEBUG] switch_channel.c:2309
(sofia/internal/9055599XXXXX) Callstate Change EARLY -> HANGUP
2010-08-17 22:41:52.000488 [NOTICE] switch_ivr_originate.c:3282 Hangup
sofia/internal/9055599XXXXX [CS_CONSUME_MEDIA] [NO_ANSWER]
2010-08-17 22:41:52.000488 [DEBUG] switch_channel.c:2325 Send signal
sofia/internal/9055599XXXXX [KILL]
2010-08-17 22:41:52.000488 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/9055599XXXXX) Running State Change CS_HANGUP
2010-08-17 22:41:52.000488 [DEBUG] switch_core_state_machine.c:535
(sofia/internal/9055599XXXXX) State HANGUP
2010-08-17 22:41:52.000488 [DEBUG] mod_sofia.c:453 Channel
sofia/internal/9055599XXXXX hanging up, cause: NO_ANSWER
2010-08-17 22:41:52.000488 [DEBUG] switch_core_session.c:1039 Send signal
sofia/internal/9055599XXXXX [BREAK]
2010-08-17 22:41:55.204396 [DEBUG] mod_sofia.c:506 Sending CANCEL to
sofia/internal/9055599XXXXX
2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:46
sofia/internal/9055599XXXXX Standard HANGUP, cause: NO_ANSWER
2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:535
(sofia/internal/9055599XXXXX) State HANGUP going to sleep
2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/9055599XXXXX) State Change CS_HANGUP -> CS_REPORTING
2010-08-17 22:41:55.204396 [DEBUG] switch_core_session.c:1039 Send signal
sofia/internal/9055599XXXXX [BREAK]
2010-08-17 22:41:55.204396 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/9055599XXXXX) Running State Change CS_REPORTING
2010-08-17 22:41:55.205401 [DEBUG] switch_core_state_machine.c:595
(sofia/internal/9055599XXXXX) State REPORTING
2010-08-17 22:41:55.205401 [DEBUG] switch_core_state_machine.c:53
sofia/internal/9055599XXXXX Standard REPORTING, cause: NO_ANSWER
2010-08-17 22:41:55.205401 [DEBUG] switch_core_state_machine.c:595
(sofia/internal/9055599XXXXX) State REPORTING going to sleep
2010-08-17 22:41:55.206428 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/9055599XXXXX) State Change CS_REPORTING -> CS_DESTROY
2010-08-17 22:41:55.206428 [DEBUG] switch_core_session.c:1039 Send signal
sofia/internal/9055599XXXXX [BREAK]
2010-08-17 22:41:55.206428 [DEBUG] switch_core_session.c:1202 Session 18770
(sofia/internal/9055599XXXXX) Locked, Waiting on external entities
2010-08-17 22:41:55.206428 [NOTICE] switch_core_session.c:1220 Session 18770
(sofia/internal/9055599XXXXX) Ended
2010-08-17 22:41:55.206428 [NOTICE] switch_core_session.c:1222 Close Channel
sofia/internal/9055599XXXXX [CS_DESTROY]
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:427
(sofia/internal/9055599XXXXX) Callstate Change HANGUP -> DOWN
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:430
(sofia/internal/9055599XXXXX) Running State Change CS_DESTROY
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/9055599XXXXX) State DESTROY
2010-08-17 22:41:55.207463 [DEBUG] mod_sofia.c:358
sofia/internal/9055599XXXXX SOFIA DESTROY
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:60
sofia/internal/9055599XXXXX Standard DESTROY
2010-08-17 22:41:55.207463 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/9055599XXXXX) State DESTROY going to sleep

---------- Weitergeleitete Nachricht ----------
> From: Brian West <brian at freeswitch.org>
> To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
> Date: Mon, 23 Aug 2010 09:29:32 -0500
> Subject: Re: [Freeswitch-users] Wrong hangup cause (NO_ANSWER) while
> answered session
> Without that we can't help.  You also need to make sure you're on the very
> latest code.  The one thing I'm sure we get right are the hangup causes
> unless you're doing something to override them.
>
> /b
>
> On Aug 23, 2010, at 9:24 AM, Durmuş Ali Öztürk wrote:
>
> > I'm afraid, sip trace wasnt active.
>

> ---------- Weitergeleitete Nachricht ----------
> From: Steven Ayre <steveayre at gmail.com>
> To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
> Date: Mon, 23 Aug 2010 11:53:33 +0100
> Subject: Re: [Freeswitch-users] Wrong hangup cause (NO_ANSWER) while
> answered session
> Do you have a sip trace for those calls?
>
>
> On 23 August 2010 11:36, Durmuş Ali Öztürk <ali.stgt at gmail.com> wrote:
> Hello,
>
> we had some trouble while executing a bulk call process with originating a
> parallel call of 200. Because in many cases, FreeSWITCH has notified hangups
> (SWITCH_EVENT_CHANNEL_HANGUP_COMPLETE) with the wrong hangup-cause. Instead
> of notifying the successful state, we got the NO_ANSWER hangup cause. BUSY
> and NO_ANSWER states are candidates for retries, therefor many numbers are
> called/payed twice. See log below.
>
> Some other questions:
>
> B) Is the originate_timeout value an overall timer or a timer for the
> ringing (starts if SIP code 180 incomes?) stage.
>
> C) We are originating each number in a separate thread and listen to the
> channel events for updating the call result. Should we change this
> implementation or is this a good scenario/standard way. Related to the call
> result, if it is busy or not answered, the call is retried after 30 min.
> What are the recommends on this side to be ensured, the correct hangup case
> be got and the number is not called twice..
>
> D) What do I have to bear in mind for bulk calls with parallel calls over
> 200.
>
> Thanks for your answer in advance.
>

> Ali
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20100823/9b81d82f/attachment-0001.html 