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

Durmuş Ali Öztürk ali.stgt at gmail.com
Tue Aug 24 06:14:33 PDT 2010


Brian, we are not bridging calls. FreeSWITCH (Leg A) as the caller can not
be in a 'not answered' state. Also if I see 200 then it must be come from
Leg B (the callee) which means that other party has answered the call. Also,
both legs was active but FS had reported us the opposite. And this happened
more than 40.000 times between 8 hours.

I would like to know what you are expecting from the sip trace, because the
log is detailed enough to be verified that FS has catched the 200 SIP - but
it seems to be ignored (maybe hangup timer started or something else)
therefor the session is closed with the wrong state. It is also clear for
me, that FS is *over-challenged* to set the correct hangup cause in bulk
calls over 200 cps.

@Milena
We must to re-call all numbers again to give you a SIP trace but this is to
expensive for us :-)


>
> ---------- Weitergeleitete Nachricht ----------
> From: Milena <testeador01 at gmail.com>
> To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
> Date: Mon, 23 Aug 2010 10:17:37 -0500
> Subject: Re: [Freeswitch-users] Wrong hangup cause (NO_ANSWER) while
> answered session
> type "version" on the CLI
>
> If the "sip trace wasnt active" then activate it and pastebin it, that's
> the only way you can get help with this, you know the developers are experts
> not soothsayers :)
>
>
> -Mile
>
> 2010/8/23 Durmuş Ali Öztürk <ali.stgt at gmail.com>
>
>> I have setup freeswitch by using git and followed the instructions on the
>> wiki page. How can I retrieve the exact git version?
>>
>
>
> ---------- Weitergeleitete Nachricht ----------
> From: Brian West <brian at freeswitch.org>
> To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
> Date: Mon, 23 Aug 2010 10:18:30 -0500
> Subject: Re: [Freeswitch-users] Wrong hangup cause (NO_ANSWER) while
> answered session
> Again without a SIP trace I can't say... You have to remember that
> FreeSWITCH is a B2BUA and a call thru it results in TWO legs.  If you were
> to ANSWER the first but then bridge to the second then it didn't answer you
> might still get a NO_ANSWER even thou you see the 200ok for the one leg of
> the call.
>
> /b
>
> On Aug 23, 2010, at 10:08 AM, Durmuş Ali Öztürk wrote:
>
> > 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?
>
>
>
>
>
> ---------- Weitergeleitete Nachricht ----------
> From: Sergey Okhapkin <sos at sokhapkin.dyndns.org>
> To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
> Date: Mon, 23 Aug 2010 11:22:37 -0400
> Subject: Re: [Freeswitch-users] Wrong hangup cause (NO_ANSWER) while
> answered session
> You're running concurrent calls, hangup cause NO_ANSWER and log line with
> 200
> OK belong to different calls.
>
> On Monday 23 August 2010, Durmuş Ali Öztürk wrote:
> > 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/20100824/3052243f/attachment-0001.html 


More information about the FreeSWITCH-users mailing list