Asterisk, AMI, C#, SIP... Blocked by ERROR[2250]

Hello, I have very recently started working with Asterisk with no prior telecom experience whatsoever and generally mediocre network skills. I am in the process of familiarising myself with all of it and to this end have installed an asterisk server on a ubuntu server machine on my desk. My setup is successfull enough that I can call my server using zoiper and do nifty things with the dialplan. However I now need to move on to bigger challenges, and this is where I’m stuck.

I need to write some code for an application that lets me dial a number. So far I have implemented the C# example from voip-info.org and I can connect to my server using AMI. Now that I want to use the Originate action things have gone bad. To clarify, everything is done on local network, my server’s address is .42 while my client’s is .47.

My sip.conf:

[general]
context=default
localnet=0.0.0.0/255.255.255.0

[6003]
type=peer
context=from-internal
host=dynamic
insecure=invite,port

Manager.conf:
[general]
enabled = yes
;webenabled = yes

port = 5038
bindaddr = 0.0.0.0

debug = on

[testDaemon]
secret = *********

deny = 0.0.0.0/0.0.0.0
permit = 192.168.16.47/255.255.255.0

read = all
write = all

Extensions.conf:

[from-internal]
exten = hello,1,Answer()
same  = n,Wait(1)
same  = n,Playback(hello-world)
same  = n,Wait(1)
same  = n,Hangup()

sip show peers:

Name/username             Host                                    Dyn Forcerport Comedia    ACL Port     Status      Description
6003                      (Unspecified)                            D  Auto (No)  No             0        Unmonitored
1 sip peer [Monitored: 0 online, 0 offline Unmonitored: 0 online, 1 offline]

The action I send is:

Action: Originate
Channel: SIP/6003@192.168.16.47
Exten: hello
Context: from-internal
Priority: 1

And in return I get three blocks. First:

  == Using SIP RTP CoS mark 5
Audio is at 19868
Adding codec ulaw to SDP
Adding codec alaw to SDP
Adding codec gsm to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.16.47:5060:
INVITE sip:6003@192.168.16.47 SIP/2.0
Via: SIP/2.0/UDP 192.168.16.42:5060;branch=z9hG4bK3f71f735
Max-Forwards: 70
From: "Anonymous" <sip:anonymous@anonymous.invalid>;tag=as1e9966d5
To: <sip:6003@192.168.16.47>
Contact: <sip:anonymous@192.168.16.42:5060>
Call-ID: 36ea99f01a9d10825c15a34721b2cb9c@192.168.16.42:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 14.4.1
Date: Thu, 08 Jun 2017 12:19:47 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 286

v=0
o=root 378028270 378028270 IN IP4 192.168.16.42
s=Asterisk PBX 14.4.1
c=IN IP4 192.168.16.42
t=0 0
m=audio 19868 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv

---
[Jun  8 14:19:47] ERROR[2250]: chan_sip.c:4279 __sip_reliable_xmit: Serious Network Trouble; __sip_xmit returns error for pkt data
    -- Called 6003@192.168.16.47

After a little while:

Scheduling destruction of SIP dialog '36ea99f01a9d10825c15a34721b2cb9c@192.168.16.42:5060' in 32000 ms (Method: INVITE)
<-- Examining AMI event: -->
Event: Newchannel
Privilege: call,all
SequenceNumber: 49
File: manager_channels.c
Line: 761
Func: channel_snapshot_update
Channel: SIP/192.168.16.47-00000008
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: default
Exten: s
Priority: 1
Uniqueid: 1496924387.8
Linkedid: 1496924387.8


<-- Examining AMI event: -->
Event: VarSet
Privilege: dialplan,all
SequenceNumber: 50
File: manager.c
Line: 1825
Func: manager_default_msg_cb
Channel: SIP/192.168.16.47-00000008
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: default
Exten: s
Priority: 1
Uniqueid: 1496924387.8
Linkedid: 1496924387.8
Variable: SIPCALLID
Value: 36ea99f01a9d10825c15a34721b2cb9c@192.168.16.42:5060


<-- Examining AMI event: -->
Event: Newexten
Privilege: call,all
SequenceNumber: 51
File: manager_channels.c
Line: 761
Func: channel_snapshot_update
Channel: SIP/192.168.16.47-00000008
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: default
Exten:
Priority: 1
Uniqueid: 1496924387.8
Linkedid: 1496924387.8
Extension:
Application: AppDial2
AppData: (Outgoing Line)


<-- Examining AMI event: -->
Event: DialBegin
Privilege: call,all
SequenceNumber: 52
File: manager_channels.c
Line: 1173
Func: channel_dial_cb
DestChannel: SIP/192.168.16.47-00000008
DestChannelState: 0
DestChannelStateDesc: Down
DestCallerIDNum: <unknown>
DestCallerIDName: <unknown>
DestConnectedLineNum: <unknown>
DestConnectedLineName: <unknown>
DestLanguage: en
DestAccountCode:
DestContext: default
DestExten:
DestPriority: 1
DestUniqueid: 1496924387.8
DestLinkedid: 1496924387.8
DialString: 6003@192.168.16.47


<-- Examining AMI event: -->
Event: Hangup
Privilege: call,all
SequenceNumber: 53
File: manager_channels.c
Line: 761
Func: channel_snapshot_update
Channel: SIP/192.168.16.47-00000008
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: en
AccountCode:
Context: default
Exten:
Priority: 1
Uniqueid: 1496924387.8
Linkedid: 1496924387.8
Cause: 0
Cause-txt: Unknown

<-- Examining AMI event: -->
Event: DeviceStateChange
Privilege: call,all
SequenceNumber: 54
File: manager.c
Line: 1825
Func: manager_default_msg_cb
Device: SIP/192.168.16.47
State: INVALID

And finally:

Really destroying SIP dialog '36ea99f01a9d10825c15a34721b2cb9c@192.168.16.42:5060' Method: INVITE

Two things have held my interest but I cannot make anything of either.

First and foremost is of course the ERROR[2250] line. From what I could gather it tends to be a firewall error, but my ports are open on both machines. I could not find anything else useful.

Second is the From: “Anonymous” sip:anonymous@anonymous.invalid line which I have looked into as well to no avail.

Thanks in advance for any help on this problem.

As you say, the first one is a network problem.

The second one is expected behaviour if you don’t provide a caller ID.

1 Like

Try in the channel only with Channel: SIP/6003

your peer 6003 is not online - no ip in sip show peers

There are no errors, only returns a Really destroying SIP dialog line.

Whether he intended to, or not, he bypassed the sip.conf entry and initiated an anoymous request direct to the device, which would potentially work even if the device had failed to register.

I would say that appearing not online (failed to register) has a common, network related, cause with the failure to access it driectly.

Thank you for all the answers. If I get it right:

  1. My “From” is Anonymous because I did not provide a caller ID, which as I understand it is not required, so it should not impact anything else
  2. My client at peer 6003 is not online, but it doesn’t matter because it registers directly when the request is made
  3. The Originate request does not work because of a network misconfiguration or problem

Any pointers on how I could identify the source of my network problem?

Use tcpdump/wireshark to find the exact diagnostic and what is reporting it.

Use traceroute to try and find at which router things fail.

Thank you David for the suggestion. However I am unsure what I should be looking for. I have the packets list from wireshark but can’t make anything of them. Would a screenshot or a dump help?

Well you can start with basic commands like MTR and pings from one equipment to other, to check loss and latency. The wireshark capture will show you traces of all your network if you filter by SIP you can see the complete trace of each package and then check where it got lost.

Also consider to check the internal firewall in your PBX if it’s active it should be allowing sip and rtp connections.

I am on ethernet LAN between my server and client. Latency is under 1ms and there is no packet loss. There is TCP traffic on port 5038 (on which I opened the AMI socket) but there is no SIP traffic.

When running zoiper on my client machine SIP traffic happens correctly and everything works - registering, dialling et al.

On the wireshark, you are particularly looking for ICMP messages saying why the packet has been rejected, and the IP address from which those ICMP messages came.

And the internal firewall of your server?

There are no ICMP messages at all, and no rejection message - all packets carry pretty much gibberish. Messages are in the flavour of [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1. Other prefixes include ACK and PSH.

My server’s firewall is not running.

Generally a transmit error would indicate either that the Asterisk box has no route to the destination, or that it received an ICMP relating to the transmission.

Also, by default SIP uses UDP, but SYN, ACK and PSH relate to TCP. In fact, your SIP trace, even though garbled by failing to use pre-formatted text on the forum, says it is using UDP. If you are not seeing SIP UDP in the trace that does suggest that there is no route, and the packet is being rejected before it even gets into the networking subsystem.

Both ping and traceroute should confirm the case if there is no route.

There is indeed no sign of UDP in my wireshark capture. Ping works from both machines. Traceroute works from the client to the server in one hop, but doesn’t work at all from server to client - it receives “no reply” for 30 hops then returns.

No reply could reflect a policy on handling ICMP probes. You would really expect an error if Asterisk reports a network type error.

Sorry to insist, to me it looks simple, the peer with account 6003 is not online - either the softphone/phone is not started/connected, or misconfigured.
Until you see an IP adress in sip show peers for 6003, there is no to look elsewhere

Try connecting another softphone and call 6003

He’s not calling the peer 6003, he/s calling the device at 192.168.16.47, passing 6003 as the user name. As 6003 hasn’t registered, we have no idea as to whether that address represents the 6003 in sip.conf, or not. Although the failure to use preformatted text has destroyed the Contact header, it is almost certain that the Asterisk box is 192.168.16.42, so the error is not one of trying to send to 6003, at itself.

If he were calling 6003, this:

Action: Originate
Channel: SIP/6003@192.168.16.47

would say:

Action: Originate
Channel: SIP/6003

Obviously, if 6003 should be registering, he should debug the register first, and consider using SIP/6003 in the originate.

Thank you for the help thus far and sorry about the preformatted text - had not explored the fidgets enough apparently!

I still have not found the root cause of my problem unfortunately, it would seem that my AMI commands go through well but then no SIP communication happen at all from the server or the client. Unfortunately I have to leave the problem at that for the moment as I have been asked to shift priorities.

Thank you again for the replies.