[asterisk-bugs] [JIRA] (ASTERISK-19898) OriginateResponse event is received with Reason 3, 'remote end is ringing', while remote end destination is unreachable

Joshua Colp (JIRA) noreply at issues.asterisk.org
Tue Dec 19 05:51:11 CST 2017 

     [ https://issues.asterisk.org/jira/browse/ASTERISK-19898?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Joshua Colp updated ASTERISK-19898:
-----------------------------------

    Assignee: Modulus
      Status: Waiting for Feedback  (was: Open)

Are you still experiencing this as a problem under recent supported versions of Asterisk?

> OriginateResponse event is received with Reason 3, 'remote end is ringing', while remote end destination is unreachable
> -----------------------------------------------------------------------------------------------------------------------
>
>                 Key: ASTERISK-19898
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-19898
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Core/ManagerInterface
>    Affects Versions: 1.8.10.1
>         Environment: GNU/Linux (Debian Squeeze with kernel 2.6.32-5-686) on i686
>            Reporter: Modulus
>            Assignee: Modulus
>            Severity: Minor
>
> Steps to reproduce:
> 1) Remove default gw from the machine running asterisk, so that all remote destinations become unreachable.
> 2) Originate a call through AMI (SIP channel 'SIP/somepeer/XXXXXXXXXX')
> 3) Listen for OriginateResponse event
> OriginateResponse event is received with *Reason* '3', which according to frame.h means 'Remote end is ringing'.
> However, remote end has never been in ringing state because it's unreachable.
> Perhaps an interesting note here is that *Hangup cause* '3' maps to 'NO_ROUTE_DESTINATION', which seems to match exactly the situation.
> Was that '3' value meant to be assigned to the hangup cause instead of being assigned to the reason/frame type code?
> The Hangup event that comes before OriginateResponse event holds a cause value of '0' (cause-txt:unknown).
> An excerpt from logs follows:
> {noformat}
> [May 22 20:01:53] DEBUG[2741] manager.c: Running action 'Originate'
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Asked to create a SIP channel with formats: 0x40 (slin)
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Allocating new SIP dialog for 53fa663c1a81d7950d7f2d2c783ec667 at 127.0.1.1:5060 - INVITE (No RTP)
> [May 22 20:01:53] DEBUG[2747] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:01:53] DEBUG[2747] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer' AND host = 'dynamic'
> [May 22 20:01:53] DEBUG[2747] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:01:53] DEBUG[2747] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer'
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: -REALTIME- peer built. Name: somepeer. Peer objects: 1
> [May 22 20:01:53] DEBUG[2747] netsock2.c: Splitting 'sipserver.example.org' into...
> [May 22 20:01:53] DEBUG[2747] netsock2.c: ...host 'sipserver.example.org' and port ''.
> [May 22 20:01:53] DEBUG[2747] netsock2.c: Splitting 'sipserver.example.org' into...
> [May 22 20:01:53] DEBUG[2747] netsock2.c: ...host 'sipserver.example.org' and port ''.
> [May 22 20:01:53] VERBOSE[2747] srv.c:        > ast_get_srv: SRV lookup for '_sip._udp.sipserver.example.org' mapped to host sipserver.example.org, port 5060
> [May 22 20:01:53] DEBUG[2747] netsock2.c: Splitting 'sipserver.example.org' into...
> [May 22 20:01:53] DEBUG[2747] netsock2.c: ...host 'sipserver.example.org' and port ''.
> [May 22 20:01:53] DEBUG[2747] netsock2.c: Splitting 'sipserver.example.org' into...
> [May 22 20:01:53] DEBUG[2747] netsock2.c: ...host 'sipserver.example.org' and port ''.
> [May 22 20:01:53] VERBOSE[2747] dnsmgr.c:        > doing dnsmgr_lookup for 'sipserver.example.org'
> [May 22 20:01:53] VERBOSE[2747] srv.c:        > ast_get_srv: SRV lookup for '_sip._udp.sipserver.example.org' mapped to host sipserver.example.org, port 5060
> [May 22 20:01:53] DEBUG[2747] netsock2.c: Splitting 'sipserver.example.org' into...
> [May 22 20:01:53] DEBUG[2747] netsock2.c: ...host 'sipserver.example.org' and port ''.
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: -REALTIME- loading peer from database to memory. Name: somepeer. Peer objects: 1
> [May 22 20:01:53] DEBUG[2747] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9c8fbd8'
> [May 22 20:01:53] DEBUG[2747] res_rtp_asterisk.c: Allocated port 15266 for RTP instance '0x9c8fbd8'
> [May 22 20:01:53] DEBUG[2747] rtp_engine.c: RTP instance '0x9c8fbd8' is setup and ready to go
> [May 22 20:01:53] DEBUG[2747] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9c8fbd8'
> [May 22 20:01:53] VERBOSE[2747] netsock2.c:   == Using SIP RTP CoS mark 5
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Setting NAT on RTP to On
> [May 22 20:01:53] WARNING[2747] acl.c: Cannot connect
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 127.0.1.1:5060
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: *** Our native formats are 0x8 (alaw) 
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: *** Joint capabilities are 0x0 (nothing) 
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) 
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) 
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: *** Our preferred formats from the incoming channel are 0x40 (slin) 
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: This channel will not be able to handle video.
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Outgoing Call for XXXXXXXXXX
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Updating call counter for outgoing call
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: ** Our prefcodec: 0x40 (slin) 
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: -- Done with adding codecs to SDP
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw)
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Initializing initreq for method INVITE - callid 4cdc35d23bae90af1e6089a91af95f97 at 127.0.1.1:5060
> [May 22 20:01:53] DEBUG[2747] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for a.b.c.d:5060
> [May 22 20:01:53] WARNING[2747] chan_sip.c: sip_xmit of 0x9c9d290 (len 887) to a.b.c.d:5060 returned -2: Network is unreachable
> [May 22 20:01:53] ERROR[2747] chan_sip.c: Serious Network Trouble; __sip_xmit returns error for pkt data
> [May 22 20:01:53] DEBUG[2741] manager.c: Examining event:
> Event: Newchannel
> Privilege: call,all
> Channel: SIP/somepeer-00000018
> ChannelState: 0
> ChannelStateDesc: Down
> CallerIDNum: 
> CallerIDName: 
> AccountCode: 
> Exten: 
> Context: 
> Uniqueid: 1337706113.24
> [May 22 20:01:53] DEBUG[2741] manager.c: Examining event:
> Event: NewAccountCode
> Privilege: call,all
> Channel: SIP/somepeer-00000018
> Uniqueid: 1337706113.24
> AccountCode: 
> OldAccountCode: 
> [May 22 20:01:53] DEBUG[2741] manager.c: Examining event:
> Event: NewCallerid
> Privilege: call,all
> Channel: SIP/somepeer-00000018
> CallerIDNum: 2000
> CallerIDName: mytest
> Uniqueid: 1337706113.24
> CID-CallingPres: 0 (Presentation Allowed, Not Screened)
> [May 22 20:01:53] DEBUG[1278] devicestate.c: No provider found, checking channel drivers for SIP - somepeer
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: Checking device state for peer somepeer
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer' AND host = 'dynamic'
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer' AND host = 'dynamic'
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:01:53] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer'
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: -REALTIME- peer built. Name: somepeer. Peer objects: 2
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: -REALTIME- loading peer from database to memory. Name: somepeer. Peer objects: 2
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: Destroying SIP peer somepeer
> [May 22 20:01:53] DEBUG[1278] chan_sip.c: -REALTIME- peer Destroyed. Name: somepeer. Realtime Peer objects: 1
> [May 22 20:01:53] DEBUG[1278] devicestate.c: Changing state for SIP/somepeer - state 5 (Unavailable)
> [May 22 20:01:53] DEBUG[1278] devicestate.c: device 'SIP/somepeer' state '5'
> [May 22 20:01:53] DEBUG[1328] app_queue.c: Device 'SIP/somepeer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
> [May 22 20:02:23] DEBUG[2747] channel.c: Hanging up channel 'SIP/somepeer-00000018'
> [May 22 20:02:23] DEBUG[2747] chan_sip.c: Hanging up zombie call. Be scared.
> [May 22 20:02:23] DEBUG[2747] chan_sip.c: Updating call counter for outgoing call
> [May 22 20:02:23] DEBUG[2747] chan_sip.c: Hanging up channel in state Down (not UP)
> [May 22 20:02:23] DEBUG[2747] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9c8fbd8'
> [May 22 20:02:23] DEBUG[1278] devicestate.c: No provider found, checking channel drivers for SIP - somepeer
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Checking device state for peer somepeer
> [May 22 20:02:23] DEBUG[2741] manager.c: Examining event:
> Event: Hangup
> Privilege: call,all
> Channel: SIP/somepeer-00000018
> Uniqueid: 1337706113.24
> CallerIDNum: 2000
> CallerIDName: mytest
> ConnectedLineNum: 2000
> ConnectedLineName: mytest
> Cause: 0
> Cause-txt: Unknown
> [May 22 20:02:23] DEBUG[2741] manager.c: Examining event:
> Event: OriginateResponse
> Privilege: call,all
> ActionID: modfax-00000004
> Response: Failure
> Channel: SIP/somepeer/XXXXXXXXXX
> Context: MYTEST
> Exten: s
> Reason: 3
> Uniqueid: <null>
> CallerIDNum: 2000
> CallerIDName: mytest
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer' AND host = 'dynamic'
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer'
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: -REALTIME- peer built. Name: somepeer. Peer objects: 2
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: -REALTIME- loading peer from database to memory. Name: somepeer. Peer objects: 2
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Destroying SIP peer somepeer
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: -REALTIME- peer Destroyed. Name: somepeer. Realtime Peer objects: 1
> [May 22 20:02:23] DEBUG[1278] devicestate.c: Changing state for SIP/somepeer - state 5 (Unavailable)
> [May 22 20:02:23] DEBUG[1278] devicestate.c: device 'SIP/somepeer' state '5'
> [May 22 20:02:23] DEBUG[1278] devicestate.c: No provider found, checking channel drivers for SIP - somepeer
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Checking device state for peer somepeer
> [May 22 20:02:23] DEBUG[1328] app_queue.c: Device 'SIP/somepeer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer' AND host = 'dynamic'
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Connection okay.
> [May 22 20:02:23] DEBUG[1278] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_peers WHERE name = 'somepeer'
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: -REALTIME- peer built. Name: somepeer. Peer objects: 2
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: -REALTIME- loading peer from database to memory. Name: somepeer. Peer objects: 2
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: Destroying SIP peer somepeer
> [May 22 20:02:23] DEBUG[1278] chan_sip.c: -REALTIME- peer Destroyed. Name: somepeer. Realtime Peer objects: 1
> [May 22 20:02:23] DEBUG[1278] devicestate.c: Changing state for SIP/somepeer - state 5 (Unavailable)
> [May 22 20:02:23] DEBUG[1278] devicestate.c: device 'SIP/somepeer' state '5'
> [May 22 20:02:23] DEBUG[1328] app_queue.c: Device 'SIP/somepeer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue.
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.2#6252)

More information about the asterisk-bugs mailing list