SOLVED: Incoming call logged as to be to different trunk (wrong DID?)

I have been trying and searching for hours, but no success so far. Situation:

  • Distro FreePBX 2.9.0.7.
  • I have four sip trunks from the same provider (logging to same IP, just different login+psq). Each trunk is for different SIP number, let’s call them 111,222,333,444.
  • Four inbound routes including two callbacks.

PROBLEM: The thing is that when I call any number (111,222,333 or 444), FOP and “reports” log always seem to detect it as a call to 111. So I call 222, can hear IVR, but FOP says I am calling 111.
When I delete or disable trunk 111, it seems like the system “chooses” any other number and from that time, all calls seem to be as if that number was called (e.g.222), again no matter which number is really called. Even when I put back/enable again sip trunk of 111, it keeps displaying 222 as the called number (I thing it is called DID number). I think I am forgetting something in my trunk configuration, but cannot find what it is. Outbound calls are fine, “sip show registry” in command line shows all four numbers registered.

Trunks configuration (only 111 number and password is different), got four of them:
Trunk Name: 111
Outbound Caller ID: 111
CID Options: Allow any CID

OUTGOING SETTINGS
Trunk Name: 111
Peer Details:
username=111
type=peer
secret=password_for_number_111
port=5060
insecure=very
host=ip-of-my-isp-server
dtmfmode=rfc2833
call-limit=3
allow=g711

Register String: 111:password_for_number_111@ip-of-my-isp-server/111

…all other values blank(default)


Inbound routes:

  1. Description: 111 / DID number: 111 / any CID (destination is extension ‘14’)
  2. 222 / any DID / any CID (destination is time condition going to IVR)
  3. callback1 / anyDID / mobile-number1
  4. callback2 / anyDID / mobile-number2

I should mention that from the caller’s point of view, everything works fine. If someone calls 111, extension 14 rings. If 222 is called, it goes to IVR through time condition. Even callbacks from certain mobile numbers have no problem.

I should also mention I have another trunk which is connected to GOIP1 GSM gateway and directed to 7777 if someone calls it. However, as incoming and outgoing calls to this number work fine and are even well-recognized to correct trunk, I think there is no problem. However, here is the trunk config for my question to be complete:
Trunk Name: GOIP1
Outbound Caller ID: (blank)
CID Options: Allow any CID
Maximum channels: 1

OUTGOING SETTINGS
Trunk Name: GoIP1
host=192.168.1.10
port=5060
type=peer
context=from-internal
dtmfmode=rfc2833
insecure=very
qualify=yes

INCOMING SETT.
User context: goip_1
User details:
secret=*******
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
type=friend
qualify=yes

Register String: blank


ANY IDEAS?

No idea without a CLI output of an inbound call on 111 and 222. Also, in general you would have one sip trunk per provider and four DID’s passing though that trunk. What provider makes you get four trunks to get four DID’s ?

Also trunks should be in “from-trunk” context for security and to use the inbound routing function. “from-internal” is for internal resources.

The behavior you are describing is normal, especially for trunks that use insecure=very (or insecure=invite).

When a SIP call comes into Asterisk, it makes several evaluations. One of the first evaluations is whether the call is coming from a valid Trunk.

It does this by comparing the IP address where the call is coming from with the host=IP addresses of the Trunks you have set-up. Ordinarily, it would also ensure that the originating port and the username and password are correct as well. However, if you have insecure=very (or port,invite) set (as you do) in a trunk, then Asterisk makes no effort to match the username/password/port on incoming calls. Rather, as long as the host matches, then Asterisk accepts the call as coming in on that trunk. Trunks are compared in alphanumeric order, so if you have several trunks set up to the same host, every incoming call will match to the trunk with the lowest alphanumic name, i.e. 1111 before 2222, and aaaa before bbbb.

If the call matches ANY of your trunks, that’s good enough for Asterisk, and it moves the call on to the next level of processing, which is to compare the DID sent with the call with your inbound routes. It appears to process then in alphanumeric order, so whichever Trunk matches first will end up listed in the CDR.

If the call is NOT coming from a valid trunk, then Asterisk/FreePBX asks whether you have enabled “Allow Anonymous SIP Calls” from the general settings page. If you have, then that is also good enough for Asterisk, and the call gets sent on for processing the DID against an inbound route.

If neither of these are present, Asterisk answers the call and plays a message that says that “the number you have dialed is not in service at this time.”

As far as FreePBX/Asterisk is concerned, when a call comes in, as long as it is coming from an authorized host, or you’ve enabled anonymous calls, that’s all that matters.

And as long as the DID matches, the call will go wherever you want it to go.

So, I guess, other than having a interesting discussion about call processing, I’m not really sure what the problem here is?

Thanks all for the replies.

cosmicwombat: This is a low-cost provider from central Europe, who gives out SIO accounts/phone numbers automatically. Once I require a new number, IP+login+psw comes by e-mail in a few seconds. That’s all, individual configurations might be possible, but as it is low-cost and fully automated, I guess it would be difficult. I believe CLI output is the same as the part of /var/log/asterisk/full, I enclose that part of my logfile below.

SkykingOH: Please don’t be mistaken by GOIP trunk I mentioned. As far as I know, this GSM gateway is not working as a full SIP server, but just as some kind of extension, that’s why it has context=from-internal. I have mentioned it just to give my complete list of trunks, but the problem is not with this trunk. Other four “problematic” trunks had no context defined. I tried to add context=from-trunk as you say, but no change. When I call 111 FOP and “reports” (CDR?) say it is coming to 222 at the moment.

AdHominem: Thanks for such a long answer. Well my problem is basically that I do not know what number was really called in. It is very important for me as some numbers should be disabled in the future if not called for a longer time. As for the internal matching, it seems to me that it is not using alphanumeric name, but most probably the order the trunks were created/(de)activated. But it does not matter. Please consider me a beginner, I have copied the trunk definition from some example. I do not know whether I really need to have insecure=very here. All I need is to be able to call in and out to all these four numbers. The thing about same IP that all four trunks are connected to also came to my mind yesterday. I tried to define hostname for one of the trunks (which is not recommended by Freepbx due to some bug), but the result is still the same. I am sure you are right, but internally, it is probably still working with the IP. Moreover, I would need four IPs :slight_smile:

DO I GET IT RIGHT THAT THE PROBLEM IS IN MY DEFINITION OF INSECURE=VERY? How could I fix this then?


Part of the full log file-called 111, being displayed/logged as a call coming to 222. Extension 14 ringing as expected:
[2011-12-11 14:50:06] VERBOSE[3103] netsock2.c: == Using SIP RTP TOS bits 184
[2011-12-11 14:50:06] VERBOSE[3103] netsock2.c: == Using SIP RTP CoS mark 5
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [111@from-trunk:1] Set(“SIP/222-0000009c”, “__FROM_DID=111”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [111@from-trunk:2] Gosub(“SIP/222-0000009c”, “app-blacklist-check,s,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/222-0000009c”, “0?blacklisted”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/222-0000009c”, “CALLED_BLACKLIST=1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/222-0000009c”, “”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [111@from-trunk:3] ExecIf(“SIP/222-0000009c”, “0 ?Set(CALLERID(name)=311249000)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [111@from-trunk:4] Set(“SIP/222-0000009c”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [111@from-trunk:5] Set(“SIP/222-0000009c”, “CALLERPRES()=allowed_not_screened”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [111@from-trunk:6] Goto(“SIP/222-0000009c”, “from-did-direct,14,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (from-did-direct,14,1)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [14@from-did-direct:1] ExecIf(“SIP/222-0000009c”, “0?Set(__RINGTIMER=0)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [14@from-did-direct:2] Macro(“SIP/222-0000009c”, “exten-vm,novm,14,0,0,0”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/222-0000009c”, “user-callerid,”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/222-0000009c”, “AMPUSER=311249000”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/222-0000009c”, “0?report”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/222-0000009c”, “1?Set(REALCALLERIDNUM=311249000)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/222-0000009c”, “AMPUSER=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/222-0000009c”, “AMPUSERCIDNAME=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/222-0000009c”, “1?report”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-user-callerid,s,13)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/222-0000009c”, “0?continue”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:14] Set(“SIP/222-0000009c”, “__TTL=64”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/222-0000009c”, “1?continue”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-user-callerid,s,26)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/222-0000009c”, “CALLERID(number)=311249000”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/222-0000009c”, “CALLERID(name)=311249000”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/222-0000009c”, “CHANNEL(language)=en”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:2] Set(“SIP/222-0000009c”, “RingGroupMethod=none”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:3] Set(“SIP/222-0000009c”, “__EXTTOCALL=14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:4] Set(“SIP/222-0000009c”, “__PICKUPMARK=14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:5] Set(“SIP/222-0000009c”, “RT=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:6] Macro(“SIP/222-0000009c”, “record-enable,14,IN”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/222-0000009c”, “1?check”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-record-enable,s,4)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/222-0000009c”, “0?MacroExit()”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/222-0000009c”, “0?Group:OUT”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-record-enable,s,14)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/222-0000009c”, “1?IN”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-record-enable,s,18)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-record-enable:18] ExecIf(“SIP/222-0000009c”, “1?MacroExit()”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:7] GotoIf(“SIP/222-0000009c”, “1?macrodial”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-exten-vm,s,13)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:13] GosubIf(“SIP/222-0000009c”, “0?clrheader,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-exten-vm:14] Macro(“SIP/222-0000009c”, “dial-one,tr,14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:1] Set(“SIP/222-0000009c”, “DEXTEN=14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:2] Set(“SIP/222-0000009c”, “DIALSTATUS_CW=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“SIP/222-0000009c”, “0?screen,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“SIP/222-0000009c”, “0?cf,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“SIP/222-0000009c”, “1?skip1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-dial-one,s,8)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“SIP/222-0000009c”, “0?nodial”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“SIP/222-0000009c”, “0?continue”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:10] Set(“SIP/222-0000009c”, “EXTHASCW=ENABLED”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“SIP/222-0000009c”, “0?next1:cwinusebusy”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-dial-one,s,23)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:23] GotoIf(“SIP/222-0000009c”, “1?next3:continue”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-dial-one,s,24)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:24] ExecIf(“SIP/222-0000009c”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“SIP/222-0000009c”, “0?nodial”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“SIP/222-0000009c”, “1?dstring,1:dlocal,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“SIP/222-0000009c”, “DSTRING=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“SIP/222-0000009c”, “DEVICES=14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“SIP/222-0000009c”, “0?Return()”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“SIP/222-0000009c”, “0?Set(DEVICES=4)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“SIP/222-0000009c”, “LOOPCNT=1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“SIP/222-0000009c”, “ITER=1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“SIP/222-0000009c”, “THISDIAL=SIP/14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“SIP/222-0000009c”, “1?zap2dahdi,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/222-0000009c”, “0?Return()”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/222-0000009c”, “NEWDIAL=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/222-0000009c”, “LOOPCNT2=1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/222-0000009c”, “ITER2=1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/222-0000009c”, “THISPART2=SIP/14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/222-0000009c”, “0?Set(THISPART2=DAHDI/14)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/222-0000009c”, “NEWDIAL=SIP/14&”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/222-0000009c”, “ITER2=2”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/222-0000009c”, “0?begin2”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/222-0000009c”, “THISDIAL=SIP/14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/222-0000009c”, “”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“SIP/222-0000009c”, “DSTRING=SIP/14&”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“SIP/222-0000009c”, “ITER=2”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“SIP/222-0000009c”, “0?begin”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“SIP/222-0000009c”, “DSTRING=SIP/14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“SIP/222-0000009c”, “”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“SIP/222-0000009c”, “0?nodial”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“SIP/222-0000009c”, “1?skiptrace”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Goto (macro-dial-one,s,30)
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/222-0000009c”, “D_OPTIONS=tr”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/222-0000009c”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/222-0000009c”, “0?SIPAddHeader()”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/222-0000009c”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/222-0000009c”, “0?qwait,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/222-0000009c”, “__CWIGNORE=”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/222-0000009c”, “__KEEPCID=TRUE”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/222-0000009c”, “0?usegoto,1”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/222-0000009c”, “0?godial”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:39] Set(“SIP/222-0000009c”, “CONNECTEDLINE(name,i)=Bossy doma”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:40] Set(“SIP/222-0000009c”, “CONNECTEDLINE(num)=14”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:41] Set(“SIP/222-0000009c”, “D_OPTIONS=trI”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/222-0000009c”, “SIP/14,trI”) in new stack
[2011-12-11 14:50:06] VERBOSE[11636] netsock2.c: == Using SIP RTP TOS bits 184
[2011-12-11 14:50:06] VERBOSE[11636] netsock2.c: == Using SIP RTP CoS mark 5
[2011-12-11 14:50:06] VERBOSE[11636] app_dial.c: – Called SIP/14
[2011-12-11 14:50:06] VERBOSE[11636] app_dial.c: – Connected line update to SIP/222-0000009c prevented.
[2011-12-11 14:50:06] VERBOSE[11636] app_dial.c: – SIP/14-0000009d is ringing
[2011-12-11 14:50:06] VERBOSE[11636] app_dial.c: – SIP/14-0000009d is ringing
[2011-12-11 14:50:13] VERBOSE[11636] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/222-0000009c’ in macro ‘dial-one’
[2011-12-11 14:50:13] VERBOSE[11636] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on ‘SIP/222-0000009c’ in macro ‘exten-vm’
[2011-12-11 14:50:13] VERBOSE[11636] pbx.c: == Spawn extension (from-did-direct, 14, 2) exited non-zero on ‘SIP/222-0000009c’
[2011-12-11 14:50:13] VERBOSE[11636] pbx.c: – Executing [h@from-did-direct:1] Macro(“SIP/222-0000009c”, “hangupcall,”) in new stack
[2011-12-11 14:50:13] VERBOSE[11636] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/222-0000009c”, “1?theend”) in new stack
[2011-12-11 14:50:13] VERBOSE[11636] pbx.c: – Goto (macro-hangupcall,s,3)
[2011-12-11 14:50:13] VERBOSE[11636] pbx.c: – Executing [s@macro-hangupcall:3] Hangup(“SIP/222-0000009c”, “”) in new stack
[2011-12-11 14:50:13] VERBOSE[11636] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/222-0000009c’ in macro ‘hangupcall’
[2011-12-11 14:50:13] VERBOSE[11636] pbx.c: == Spawn extension (from-did-direct, h, 1) exited non-zero on ‘SIP/222-0000009c’

…sorry, forgot to mention that “allow anonymous SIP calls” are disabled (=no) in my Setup/General Settings…which should be fine as far as I undersand.

You need to post a SIP debug and your actual trunk information for that provider so we can see what does not match (hide account names and passwords).

I am sorry but isn’t the SIP debug part of the /var/log/asterisk/full I copied above? I tried some googling for “sip debug” and it says to log in via SSH and do:
asterisk -vvvvvvvvvvr
freepbx*CLI>sip debug
No such command ‘sip debug’ (type ‘core show help sip debug’ for other possible commands)

So sorry for such basic question, but how do I get the SIP debug you are asking for?

I posted all my trunk configuration above. The only thing I changed were passwords and real phone numbers as they are same as login names.

As it seems to be a problem of having insecure=very in all four trunk configs connecting to same IP(=same provider), I tried to delete it in all four trunks. Sadly, incoming calls stopped working with error:
[2011-12-11 21:55:04] NOTICE[3103] chan_sip.c: Failed to authenticate device “caller’s-number” <sip:caller’s-number@ip-of-my-provider>;tag=as4830bda6

So any idea how to tell Freepbx/Asterisk what trunk name(=number) the call is coming from?

I think we have some conceptual issues that you are struggling with.

First let’s get the mechanics out of the way.

SIP debug is from an old version of Asterisk, sip set debug on is the syntax for the latest version. When using the CLI you can use the ? to obtain syntax ‘sip ?’ will show you all commands associated with sip, 'sip set ?" will give you all the set options. This works in all modules.

You don’t ‘tell FreePBX’ what number a call arrives on. Trunks are Asterisk peers. You construct your peer so that it matches your incoming invite based on the minimum required number of variables to create a unique, qualified match. You can use any Asterisk variable listed under “peers and clients” in the FreePBX trunk module.

The most complete and up to date variables are listed in the sample sip.conf included with Asterisk.

However you can use this web page as a reference.

Thank you for the info, I have got the sip debug now (see below). You are right, I need to change the trunk definitions so that it matches my criteria. I already know the problem is insecure=very in my definitions. As all four trunks are connected to the same IP (same provider), the first that matches the criteria is considered to be ok. I just do not know how to change the criteria. Basically, I need to add “some” criteria to the trunk definitions telling if DID does not match, then do not receive call through that trunk. Or alternatively I was thinking of “marking” it somehow so that in CDR i see which one of the numbers (=trunks) were called. I have read all the variables on the web page you sent me (thank you), but not really sure which one would help me. Was thinking about amaflags, but as far as it does not change the trunk criteria but just categorizes the call within already-wrong-trunk, I am unsure this is the right way to go.

All I need is to know what number was called in CDR. Now, all incoming calls to all numbers are logged in CDR as a channel SIP/222-00000xxx (where 00000xxx is a call number I guess).

Here is my sip debug. Again, all I replaced were my original 9-digit phone numbers (=loginnames) to 111, 222, 333, 444. In this case, I made a call from a number 724522113 to 111, which is again logged in CDR as a call to channel SIP/222:
[root@freepbx ~]# asterisk -r
Asterisk 1.8.6.0, Copyright © 1999 - 2011 Digium, Inc. and others.
Created by Mark Spencer [email protected]
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core show warranty’ for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type ‘core show license’ for details.

Connected to Asterisk 1.8.6.0 currently running on freepbx (pid = 2926)
Verbosity is at least 10
freepbxCLI> sip set debug peer 111
SIP Debugging Enabled for IP: 81.91.216.18
freepbx
CLI> sip set debug peer 222
SIP Debugging Enabled for IP: 81.91.216.18
[2011-12-12 10:15:11] NOTICE[3103]: chan_sip.c:13946 check_auth: Correct auth, but based on stale nonce received from ‘sip:[email protected];tag=1784587034’
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:12593 sip_reregister: – Re-registration for [email protected]
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK4e041958;rport
Max-Forwards: 70
From: sip:[email protected];tag=as51ef39b0
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 882 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“333”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“0d424f99”, response="80e5a8d01c6a9d07caa764fe15bcb80b"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK4e041958;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as51ef39b0
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 882 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK4e041958;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as51ef39b0
To: sip:[email protected];tag=as57b27227
Call-ID: [email protected]
CSeq: 882 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="130396a1"
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Responding to challenge, registration to domain/host name 81.91.216.18
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK7ea954b1;rport
Max-Forwards: 70
From: sip:[email protected];tag=as04ac7ce6
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“333”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“130396a1”, response="116eee22e597643988bb9503c00fa043"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK7ea954b1;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as04ac7ce6
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
OPTIONS sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK7c0c39f7;rport
Max-Forwards: 70
From: “asterisk” sip:[email protected];tag=as457c1a46
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.7.0
Date: Mon, 12 Dec 2011 09:15:20 GMT
Session-Expires: 120
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (15 headers 0 lines) —
Looking for 333 in from-sip-external (domain 192.168.1.7:5060)

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK7c0c39f7;received=81.91.216.18;rport=5060
From: “asterisk” sip:[email protected];tag=as457c1a46
To: sip:[email protected]:5060;tag=as22de8bdc
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:192.168.1.7:5060
Accept: application/sdp
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 32000 ms (Method: OPTIONS)

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK7ea954b1;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as04ac7ce6
To: sip:[email protected];tag=as57b27227
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Expires: 120
Contact: sip:[email protected]:5060;expires=120
Date: Mon, 12 Dec 2011 09:15:20 GMT
Content-Length: 0

<------------->
— (13 headers 0 lines) —
Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:20125 handle_response_register: Outbound Registration: Expiry for 81.91.216.18 is 120 sec (Scheduling reregistration in 105 s)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:12593 sip_reregister: – Re-registration for [email protected]
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK769aa37d;rport
Max-Forwards: 70
From: sip:[email protected];tag=as435f4545
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 882 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“111”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“047f948e”, response="18c472381ec1be0ae50e1b41a97ef56f"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK769aa37d;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as435f4545
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 882 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK769aa37d;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as435f4545
To: sip:[email protected];tag=as3e5bd1e9
Call-ID: [email protected]
CSeq: 882 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="515c8cbe"
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Responding to challenge, registration to domain/host name 81.91.216.18
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK31bab95c;rport
Max-Forwards: 70
From: sip:[email protected];tag=as4bda06d5
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“111”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“515c8cbe”, response="22dbbb7fbeeae224ce968adfa26ad315"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK31bab95c;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as4bda06d5
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
OPTIONS sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK4c32c80b;rport
Max-Forwards: 70
From: “asterisk” sip:[email protected];tag=as5450d479
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.7.0
Date: Mon, 12 Dec 2011 09:15:20 GMT
Session-Expires: 120
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (15 headers 0 lines) —
Looking for 111 in from-sip-external (domain 192.168.1.7:5060)

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK4c32c80b;received=81.91.216.18;rport=5060
From: “asterisk” sip:[email protected];tag=as5450d479
To: sip:[email protected]:5060;tag=as33138f9c
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:192.168.1.7:5060
Accept: application/sdp
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 32000 ms (Method: OPTIONS)

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK31bab95c;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as4bda06d5
To: sip:[email protected];tag=as3e5bd1e9
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Expires: 120
Contact: sip:[email protected]:5060;expires=120
Date: Mon, 12 Dec 2011 09:15:20 GMT
Content-Length: 0

<------------->
— (13 headers 0 lines) —
Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:20125 handle_response_register: Outbound Registration: Expiry for 81.91.216.18 is 120 sec (Scheduling reregistration in 105 s)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:12593 sip_reregister: – Re-registration for [email protected]
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK33a53d4e;rport
Max-Forwards: 70
From: sip:[email protected];tag=as2d8d69dc
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 882 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“222”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“03a54dcd”, response="466ded77bacddca64dcffcf75f7eea72"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK33a53d4e;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as2d8d69dc
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 882 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK33a53d4e;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as2d8d69dc
To: sip:[email protected];tag=as345840fc
Call-ID: [email protected]
CSeq: 882 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="1d40bde7"
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Responding to challenge, registration to domain/host name 81.91.216.18
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK4d91db66;rport
Max-Forwards: 70
From: sip:[email protected];tag=as60cef5c7
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“222”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“1d40bde7”, response="3923a900c3f093cc96835317ea441998"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK4d91db66;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as60cef5c7
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
OPTIONS sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK630eba2b;rport
Max-Forwards: 70
From: “asterisk” sip:[email protected];tag=as5c8a813b
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.7.0
Date: Mon, 12 Dec 2011 09:15:20 GMT
Session-Expires: 120
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (15 headers 0 lines) —
Looking for 222 in from-sip-external (domain 192.168.1.7:5060)

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK630eba2b;received=81.91.216.18;rport=5060
From: “asterisk” sip:[email protected];tag=as5c8a813b
To: sip:[email protected]:5060;tag=as7512ff5c
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:192.168.1.7:5060
Accept: application/sdp
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 32000 ms (Method: OPTIONS)

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK4d91db66;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as60cef5c7
To: sip:[email protected];tag=as345840fc
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Expires: 120
Contact: sip:[email protected]:5060;expires=120
Date: Mon, 12 Dec 2011 09:15:20 GMT
Content-Length: 0

<------------->
— (13 headers 0 lines) —
Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:20125 handle_response_register: Outbound Registration: Expiry for 81.91.216.18 is 120 sec (Scheduling reregistration in 105 s)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:12593 sip_reregister: – Re-registration for [email protected]
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK25d40a71;rport
Max-Forwards: 70
From: sip:[email protected];tag=as4703f3b8
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“444”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“7cf5dca9”, response="0a091e24e193b40d350b9ad4376459d3"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK25d40a71;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as4703f3b8
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK25d40a71;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as4703f3b8
To: sip:[email protected];tag=as49d311a2
Call-ID: [email protected]
CSeq: 883 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="5a6efcf9"
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Responding to challenge, registration to domain/host name 81.91.216.18
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 81.91.216.18:5060:
REGISTER sip:81.91.216.18 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK5a3a8f96;rport
Max-Forwards: 70
From: sip:[email protected];tag=as7930c9be
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 884 REGISTER
User-Agent: FPBX-2.9.0(1.8.6.0)
Authorization: Digest username=“444”, realm=“asterisk”, algorithm=MD5, uri=“sip:81.91.216.18”, nonce=“5a6efcf9”, response="a59b5d5f5328b99ae12ab7b030d70c7e"
Expires: 120
Contact: sip:[email protected]:5060
Content-Length: 0


<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK5a3a8f96;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as7930c9be
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 884 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:81.91.216.18:5060 —>
OPTIONS sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK636f29b2;rport
Max-Forwards: 70
From: “asterisk” sip:[email protected];tag=as28527fce
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.7.0
Date: Mon, 12 Dec 2011 09:15:21 GMT
Session-Expires: 120
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------->
— (15 headers 0 lines) —
Looking for 444 in from-sip-external (domain 192.168.1.7:5060)

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK636f29b2;received=81.91.216.18;rport=5060
From: “asterisk” sip:[email protected];tag=as28527fce
To: sip:[email protected]:5060;tag=as14291704
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:192.168.1.7:5060
Accept: application/sdp
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 32000 ms (Method: OPTIONS)

<— SIP read from UDP:81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.7:5060;branch=z9hG4bK5a3a8f96;received=192.168.1.7;rport=5060
From: sip:[email protected];tag=as7930c9be
To: sip:[email protected];tag=as49d311a2
Call-ID: [email protected]
CSeq: 884 REGISTER
Server: Asterisk PBX 1.8.7.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Expires: 120
Contact: sip:[email protected]:5060;expires=120
Date: Mon, 12 Dec 2011 09:15:21 GMT
Content-Length: 0

<------------->
— (13 headers 0 lines) —
Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[2011-12-12 10:15:21] NOTICE[3103]: chan_sip.c:20125 handle_response_register: Outbound Registration: Expiry for 81.91.216.18 is 120 sec (Scheduling reregistration in 105 s)

<— SIP read from UDP:81.91.216.18:5060 —>
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;rport
Max-Forwards: 70
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.8.7.0
Date: Mon, 12 Dec 2011 09:15:22 GMT
Session-Expires: 120
Min-SE: 90
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 326

v=0
o=root 470101552 470101552 IN IP4 81.91.216.18
s=Asterisk PBX 1.8.7.0
c=IN IP4 81.91.216.18
t=0 0
m=audio 11444 RTP/AVP 8 0 97 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
<------------->
— (16 headers 15 lines) —
Sending to 81.91.216.18:5060 (NAT)
Using INVITE request as basis request - [email protected]:5060
Found peer ‘222’ for ‘724522113’ from 81.91.216.18:5060
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 97
Found RTP audio format 3
Found RTP audio format 101
Found audio description format PCMA for ID 8
Found audio description format PCMU for ID 0
Found audio description format iLBC for ID 97
Found audio description format GSM for ID 3
Found audio description format telephone-event for ID 101
Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x40e (gsm|ulaw|alaw|ilbc)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 81.91.216.18:11444
Looking for 111 in from-trunk (domain 192.168.1.7:5060)
list_route: hop: sip:[email protected]:5060

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;received=81.91.216.18;rport=5060
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 INVITE
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Session-Expires: 120;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [111@from-trunk:1] Set(“SIP/222-000000c1”, “__FROM_DID=111”) in new stack
– Executing [111@from-trunk:2] Gosub(“SIP/222-000000c1”, “app-blacklist-check,s,1”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“SIP/222-000000c1”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“SIP/222-000000c1”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/222-000000c1”, “”) in new stack
– Executing [111@from-trunk:3] ExecIf(“SIP/222-000000c1”, “0 ?Set(CALLERID(name)=724522113)”) in new stack
– Executing [111@from-trunk:4] Set(“SIP/222-000000c1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
– Executing [111@from-trunk:5] Set(“SIP/222-000000c1”, “CALLERPRES()=allowed_not_screened”) in new stack
– Executing [111@from-trunk:6] Goto(“SIP/222-000000c1”, “from-did-direct,14,1”) in new stack
– Goto (from-did-direct,14,1)
– Executing [14@from-did-direct:1] ExecIf(“SIP/222-000000c1”, “0?Set(__RINGTIMER=0)”) in new stack
– Executing [14@from-did-direct:2] Macro(“SIP/222-000000c1”, “exten-vm,novm,14,0,0,0”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“SIP/222-000000c1”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/222-000000c1”, “AMPUSER=724522113”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/222-000000c1”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/222-000000c1”, “1?Set(REALCALLERIDNUM=724522113)”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/222-000000c1”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/222-000000c1”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/222-000000c1”, “1?report”) in new stack
– Goto (macro-user-callerid,s,13)
– Executing [s@macro-user-callerid:13] GotoIf(“SIP/222-000000c1”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:14] Set(“SIP/222-000000c1”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:15] GotoIf(“SIP/222-000000c1”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,26)
– Executing [s@macro-user-callerid:26] Set(“SIP/222-000000c1”, “CALLERID(number)=724522113”) in new stack
– Executing [s@macro-user-callerid:27] Set(“SIP/222-000000c1”, “CALLERID(name)=724522113”) in new stack
– Executing [s@macro-user-callerid:28] Set(“SIP/222-000000c1”, “CHANNEL(language)=en”) in new stack
– Executing [s@macro-exten-vm:2] Set(“SIP/222-000000c1”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“SIP/222-000000c1”, “__EXTTOCALL=14”) in new stack
– Executing [s@macro-exten-vm:4] Set(“SIP/222-000000c1”, “__PICKUPMARK=14”) in new stack
– Executing [s@macro-exten-vm:5] Set(“SIP/222-000000c1”, “RT=”) in new stack
– Executing [s@macro-exten-vm:6] Macro(“SIP/222-000000c1”, “record-enable,14,IN”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“SIP/222-000000c1”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] ExecIf(“SIP/222-000000c1”, “0?MacroExit()”) in new stack
– Executing [s@macro-record-enable:5] GotoIf(“SIP/222-000000c1”, “0?Group:OUT”) in new stack
– Goto (macro-record-enable,s,14)
– Executing [s@macro-record-enable:14] GotoIf(“SIP/222-000000c1”, “1?IN”) in new stack
– Goto (macro-record-enable,s,18)
– Executing [s@macro-record-enable:18] ExecIf(“SIP/222-000000c1”, “1?MacroExit()”) in new stack
– Executing [s@macro-exten-vm:7] GotoIf(“SIP/222-000000c1”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,13)
– Executing [s@macro-exten-vm:13] GosubIf(“SIP/222-000000c1”, “0?clrheader,1”) in new stack
– Executing [s@macro-exten-vm:14] Macro(“SIP/222-000000c1”, “dial-one,tr,14”) in new stack
– Executing [s@macro-dial-one:1] Set(“SIP/222-000000c1”, “DEXTEN=14”) in new stack
– Executing [s@macro-dial-one:2] Set(“SIP/222-000000c1”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:3] GosubIf(“SIP/222-000000c1”, “0?screen,1”) in new stack
– Executing [s@macro-dial-one:4] GosubIf(“SIP/222-000000c1”, “0?cf,1”) in new stack
– Executing [s@macro-dial-one:5] GotoIf(“SIP/222-000000c1”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,8)
– Executing [s@macro-dial-one:8] GotoIf(“SIP/222-000000c1”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:9] GotoIf(“SIP/222-000000c1”, “0?continue”) in new stack
– Executing [s@macro-dial-one:10] Set(“SIP/222-000000c1”, “EXTHASCW=ENABLED”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“SIP/222-000000c1”, “0?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,23)
– Executing [s@macro-dial-one:23] GotoIf(“SIP/222-000000c1”, “1?next3:continue”) in new stack
– Goto (macro-dial-one,s,24)
– Executing [s@macro-dial-one:24] ExecIf(“SIP/222-000000c1”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
– Executing [s@macro-dial-one:25] GotoIf(“SIP/222-000000c1”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:26] GosubIf(“SIP/222-000000c1”, “1?dstring,1:dlocal,1”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“SIP/222-000000c1”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“SIP/222-000000c1”, “DEVICES=14”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“SIP/222-000000c1”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“SIP/222-000000c1”, “0?Set(DEVICES=4)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“SIP/222-000000c1”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“SIP/222-000000c1”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“SIP/222-000000c1”, “THISDIAL=SIP/14”) in new stack
– Executing [dstring@macro-dial-one:8] GosubIf(“SIP/222-000000c1”, “1?zap2dahdi,1”) in new stack
– Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/222-000000c1”, “0?Return()”) in new stack
– Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/222-000000c1”, “NEWDIAL=”) in new stack
– Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/222-000000c1”, “LOOPCNT2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/222-000000c1”, “ITER2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/222-000000c1”, “THISPART2=SIP/14”) in new stack
– Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/222-000000c1”, “0?Set(THISPART2=DAHDI/14)”) in new stack
– Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/222-000000c1”, “NEWDIAL=SIP/14&”) in new stack
– Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/222-000000c1”, “ITER2=2”) in new stack
– Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/222-000000c1”, “0?begin2”) in new stack
– Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/222-000000c1”, “THISDIAL=SIP/14”) in new stack
– Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/222-000000c1”, “”) in new stack
– Executing [dstring@macro-dial-one:9] Set(“SIP/222-000000c1”, “DSTRING=SIP/14&”) in new stack
– Executing [dstring@macro-dial-one:10] Set(“SIP/222-000000c1”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:11] GotoIf(“SIP/222-000000c1”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:12] Set(“SIP/222-000000c1”, “DSTRING=SIP/14”) in new stack
– Executing [dstring@macro-dial-one:13] Return(“SIP/222-000000c1”, “”) in new stack
– Executing [s@macro-dial-one:27] GotoIf(“SIP/222-000000c1”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GotoIf(“SIP/222-000000c1”, “1?skiptrace”) in new stack
– Goto (macro-dial-one,s,30)
– Executing [s@macro-dial-one:30] Set(“SIP/222-000000c1”, “D_OPTIONS=tr”) in new stack
– Executing [s@macro-dial-one:31] ExecIf(“SIP/222-000000c1”, “0?SIPAddHeader(Alert-Info: )”) in new stack
– Executing [s@macro-dial-one:32] ExecIf(“SIP/222-000000c1”, “0?SIPAddHeader()”) in new stack
– Executing [s@macro-dial-one:33] ExecIf(“SIP/222-000000c1”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial-one:34] GosubIf(“SIP/222-000000c1”, “0?qwait,1”) in new stack
– Executing [s@macro-dial-one:35] Set(“SIP/222-000000c1”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:36] Set(“SIP/222-000000c1”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:37] GotoIf(“SIP/222-000000c1”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:38] GotoIf(“SIP/222-000000c1”, “0?godial”) in new stack
– Executing [s@macro-dial-one:39] Set(“SIP/222-000000c1”, “CONNECTEDLINE(name,i)=Bossy doma”) in new stack
– Executing [s@macro-dial-one:40] Set(“SIP/222-000000c1”, “CONNECTEDLINE(num)=14”) in new stack
– Executing [s@macro-dial-one:41] Set(“SIP/222-000000c1”, “D_OPTIONS=trI”) in new stack
– Executing [s@macro-dial-one:42] Dial(“SIP/222-000000c1”, “SIP/14,trI”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called SIP/14

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;received=81.91.216.18;rport=5060
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060;tag=as47af9b88
Call-ID: [email protected]:5060
CSeq: 102 INVITE
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Session-Expires: 120;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Connected line update to SIP/222-000000c1 prevented.
– SIP/14-000000c2 is ringing

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;received=81.91.216.18;rport=5060
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060;tag=as47af9b88
Call-ID: [email protected]:5060
CSeq: 102 INVITE
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Session-Expires: 120;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– SIP/14-000000c2 is ringing

<— SIP read from UDP:81.91.216.18:5060 —>
CANCEL sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;rport
Max-Forwards: 70
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 CANCEL
User-Agent: Asterisk PBX 1.8.7.0
Content-Length: 0

<------------->
— (9 headers 0 lines) —
Sending to 81.91.216.18:5060 (NAT)

<— Reliably Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;received=81.91.216.18;rport=5060
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060;tag=as47af9b88
Call-ID: [email protected]:5060
CSeq: 102 INVITE
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>

<— Transmitting (NAT) to 81.91.216.18:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;received=81.91.216.18;rport=5060
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060;tag=as47af9b88
Call-ID: [email protected]:5060
CSeq: 102 CANCEL
Server: FPBX-2.9.0(1.8.6.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
== Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/222-000000c1’ in macro ‘dial-one’
== Spawn extension (macro-exten-vm, s, 14) exited non-zero on ‘SIP/222-000000c1’ in macro ‘exten-vm’
== Spawn extension (from-did-direct, 14, 2) exited non-zero on ‘SIP/222-000000c1’
– Executing [h@from-did-direct:1] Macro(“SIP/222-000000c1”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/222-000000c1”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] Hangup(“SIP/222-000000c1”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/222-000000c1’ in macro ‘hangupcall’
== Spawn extension (from-did-direct, h, 1) exited non-zero on ‘SIP/222-000000c1’

<— SIP read from UDP:81.91.216.18:5060 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 81.91.216.18:5060;branch=z9hG4bK5b83255c;rport
Max-Forwards: 70
From: “724522113” sip:[email protected];tag=as0e8a36bc
To: sip:[email protected]:5060;tag=as47af9b88
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 ACK
User-Agent: Asterisk PBX 1.8.7.0
Content-Length: 0

<------------->
— (10 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]:5060’ Method: ACK
freepbxCLI> sip set debug off
SIP Debugging Disabled
freepbx
CLI>

Yes, your problem is insecure=very. Unfortunately, your provider will not deliver calls to you unless you have insecure=very set. As a result, Asterisk will match the incoming calls to the first trunk it finds with the matching IP address, and there’s nothing you can do about it.

But, since there’s no reason to use multiple trunks with the same provider, this is a total non-issue. One trunk can pass multiple calls and multiple DIDs. If you must use multiple trunks for some reason, the fact that Asterisk matches calls to the wrong trunk is of no functional consequence.

Well OK I got it. So a question arises: As all I need to know is which one of the four numbers was called, will it help me to persuade my provider to deliver calls for all four of my numbers(DIDs) in one trunk? Will that help me or will I just find in CDR records as a channel SIP/trunkname-… as I do now? Any other way of logging what number was called except of having each from a different provider(=different IP)?

As I see in logfile that the DID is known to Asterisk, I just thought that I could make some manual definitions/conditions like I found today in this example (http://www.freepbx.org/support/documentation/howtos/how-to-get-the-did-of-a-sip-trunk-when-the-provider-doesnt-send-it-and-). However as this does not work for me in a way of logging a called-in number into CDR, I think I am gonna give it up :frowning:

Finally! Instead of playing with trunks, what helped me was to enable displaying DID in Reports (CDR). Here is what works for me:
http://www.dusek.eu/asterisk-freepbx-what-number-was-called-more-trunks-wrong-did/