[Freeswitch-users] Overriding 480 with 200 from other leg

Wed Feb 9 02:09:02 MSK 2011

What is the hangup cause for the blegs from the CDRs?

Can you get debug logs and a siptrace for the call?

Look at the uuid parameter of mod_logfile which would make the log easy to get using grep.

A siptrace could be collected via tcpdump to a file and tshark to extract from it using Call-ID. You can also use 'sofia global siptrace on', but that'll be hard to extract on a high volume server.

I'm guessing the bleg is returning an error cause in the reason header, or there's a codec problem which the log would probably show.

Steve on iPhone

On 8 Feb 2011, at 18:05, "Peder" <peder at networkoblivion.com> wrote:

> I've got a strange issue and I am not 100% sure how to get around it.  
> 
> We have a system setup where a user calls in and enters a code.  A perl
> script is called that does an http get to find a phone number to dial, it
> dials the number, bridges the two and then it records the call.  
> 
> Once the code is verified and we have the number, we set two carriers to
> call, primary and backup.  This all works great 95%+ of the time.  We do 40k
> calls per month and about 50 calls a week run into a scenario that I am not
> sure of.   On the ones that don't work, it gets all the way through bridging
> the calls with no problem, but when the user hangs up, it doesn't hang up,
> it falls to the backup bridge and calls the destination number again our
> carrier2, all the while still recording.  We get 3 CDR records, incoming,
> call out carrier1 and call out carrier2.
> 
> Here is the snippet of the perl script that does the dialing ($bridge and
> $backupbridge are the two carriers to call).  If $bridge fails, it goes back
> to $backupbridge just fine:
> 
> $session->execute("set","continue_on_fail=true");
> $session->execute("bridge","sofia/gateway/$bridge/$PhoneNo");
> $session->execute("export","nolocal:CARRIER=${backupbridge}");
> $session->execute("bridge","sofia/gateway/$backupbridge/$PhoneNo");
> 
> 
> Every now and then we see this in the logs "Overriding SIP cause 480 with
> 200 from the other leg":
> 
> 
> 2011-01-19 09:24:50.751368 [NOTICE] sofia.c:481 Hangup
> sofia/external/1xxxxxx8003 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
> 2011-01-19 09:24:50.753368 [DEBUG] switch_channel.c:2071 Send signal
> sofia/external/1xxxxxx8003 [KILL]
> 2011-01-19 09:24:50.753368 [DEBUG] switch_core_session.c:1018 Send signal
> sofia/external/1xxxxxx8003 [BREAK]
> 2011-01-19 09:24:50.761364 [DEBUG] switch_ivr_bridge.c:478
> sofia/external/1xxxxxx8003 ending bridge by request from read function
> 2011-01-19 09:24:50.761364 [DEBUG] switch_ivr_bridge.c:565 BRIDGE THREAD
> DONE [sofia/external/1xxxxxx8003]
> 2011-01-19 09:24:50.761364 [DEBUG] switch_ivr_bridge.c:585 Send signal
> sofia/internal/yyyyyy6168 at 72.249.14.242 [BREAK]
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:351
> (sofia/external/1xxxxxx8003) State EXCHANGE_MEDIA going to sleep
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/1xxxxxx8003) Running State Change CS_HANGUP
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:499
> (sofia/external/1xxxxxx8003) State HANGUP
> 2011-01-19 09:24:50.761364 [DEBUG] mod_sofia.c:405
> sofia/external/1xxxxxx8003 Overriding SIP cause 480 with 200 from the other
> leg
> 2011-01-19 09:24:50.761364 [DEBUG] mod_sofia.c:411 Channel
> sofia/external/1xxxxxx8003 hanging up, cause: NORMAL_CLEARING
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:46
> sofia/external/1xxxxxx8003 Standard HANGUP, cause: NORMAL_CLEARING
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:499
> (sofia/external/1xxxxxx8003) State HANGUP going to sleep
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:333
> (sofia/external/1xxxxxx8003) State Change CS_HANGUP -> CS_REPORTING
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_session.c:1018 Send signal
> sofia/external/1xxxxxx8003 [BREAK]
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/1xxxxxx8003) Running State Change CS_REPORTING
> 2011-01-19 09:24:50.761364 [DEBUG] switch_core_state_machine.c:590
> (sofia/external/1xxxxxx8003) State REPORTING
> 2011-01-19 09:24:50.763475 [DEBUG] switch_core_session.c:638 Send signal
> sofia/internal/yyyyyy6168 at 72.249.14.242 [BREAK]
> 2011-01-19 09:24:50.763475 [DEBUG] switch_ivr_bridge.c:565 BRIDGE THREAD
> DONE [sofia/internal/yyyyyy6168 at 72.249.14.242]
> 2011-01-19 09:24:50.763475 [DEBUG] switch_ivr_bridge.c:585 Send signal
> sofia/external/1xxxxxx8003 [BREAK]
> EXECUTE sofia/internal/yyyyyy6168 at 72.249.14.242
> export(nolocal:CARRIER=carrier2)
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_state_machine.c:53
> sofia/external/1xxxxxx8003 Standard REPORTING, cause: NORMAL_CLEARING
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_state_machine.c:590
> (sofia/external/1xxxxxx8003) State REPORTING going to sleep
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_state_machine.c:327
> (sofia/external/1xxxxxx8003) State Change CS_REPORTING -> CS_DESTROY
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_session.c:1018 Send signal
> sofia/external/1xxxxxx8003 [BREAK]
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_session.c:1161 Session 96783
> (sofia/external/1xxxxxx8003) Locked, Waiting on external entities
> 2011-01-19 09:24:50.766348 [NOTICE] switch_core_session.c:1179 Session 96783
> (sofia/external/1xxxxxx8003) Ended
> 2011-01-19 09:24:50.766348 [NOTICE] switch_core_session.c:1181 Close Channel
> sofia/external/1xxxxxx8003 [CS_DESTROY]
> 2011-01-19 09:24:50.766348 [DEBUG] mod_dptools.c:898 EXPORT (REMOTE ONLY)
> [CARRIER]=[carrier2]
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_state_machine.c:428
> (sofia/external/1xxxxxx8003) Running State Change CS_DESTROY
> 2011-01-19 09:24:50.766348 [DEBUG] switch_core_state_machine.c:439
> (sofia/external/1xxxxxx8003) State DESTROY
> 2011-01-19 09:24:50.766348 [DEBUG] mod_sofia.c:338
> sofia/external/1xxxxxx8003 SOFIA DESTROY
> EXECUTE sofia/internal/yyyyyy6168 at 72.249.14.242
> bridge(sofia/gateway/carrier2/1xxxxxx8003)
> 
> 
> I am guessing that carrier1 is sending back a 480, so FS thinks it never
> worked and then bridges out carrier2.  Our FS is pretty old, FreeSWITCH
> Version 1.0.trunk (17043), but I don't think it is an FS issue, I think it
> is just a dialplan issue that I don't know how to resolve.  Any idea how to
> stop this from happening?  
> 
> Peder
> 
> 
> 
> 
> 
> _______________________________________________
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org