No outgoing calls

asofan · July 15, 2012, 1:13pm

Hi everyone,

This is my first post so please bare with me.

I installed elastix on a virtual box and setup extensions, outbound routes and a trunk using poivy.com (betamax voip provider).

I can make internal calls between extensions but when I dial out, it rings several times and it says “no answer”. I’ve tried everything.

the peer settings are as follows:

host=sip.poivy.com
username=XXXXX
secret=XXXXX
type=peer
nat=yes

Can someone help me?

alan · July 15, 2012, 4:50pm

It would be helpful if you told us exactly what versions of Asterisk and freePBX you are using. Also logs would be nice.

asofan · July 15, 2012, 6:16pm

Thanks alan for your reply.

You are right, I need to post some more information.Here is step by step what I did from the begining:

I downloaded and installed the latest version of Oracle’s Virtual Box.
I downloaded the latest iso of Trixbox CE [ stable release 2.8.0.4] from their website.
In virtual box I created a virtual machine with 512 ram and 8Gig dynamic virtual hard drive.

4)I changed the network settings in the virtual machine to “Bridged Adapter” and loaded the trixbox iso image in the storage tree.

5)I started the virtual machine, it loaded the iso image and proceeded with the installation as described here:

http://call-cheap.blogspot.com/2010/12/installing-trixbox-in-virtualbox.html#tut2_inst_trixbox

6)After the install was complete, I logged into the trixbox virtual machine with root account and used the “system-config-network-tui” to configure the network settings as follows:

    Manual Ip address: 192.168.1.201
    Network mask: 255.255.255.0
    Default Gateway: 192.168.1.1 (which is my tp-link router)

I logged on to trixbox web ui (http://192.168.1.201) and setup two extensions (508) and (509) and tested these two extensions with sipdroid with my android phone and x-lite on my laptop and they both worked successfully.
I added a trunk but I did not fill anything other than these two boxes:

Outgoing
Trunk name: Poivy
Peer details:
```
     host=sip.poivy.com
     username=XXXXX
     secret=XXXXX
     type=peer
     nat=yes
```
I then added an outbound route but I only filled this information and touched nothing else:
```
Route Name: Poivy
Dial Pattern: 6.
Trunk Sequence: 0 Sip/Poivy
```

That’s everything I did from start to finish.

Now, When I use Sipdroid to dial “600967737606070” using extension 509 created above, it rings over and over but it does not really connect to the trunk and the phone I’m calling does not ring. I checked the trunk provider CDR records and the re is no mention of the call.

This is a screenshot of the Trixbox status: http://tinypic.com/r/2ykfleb/6

And this is a screenshot of the pBX status: http://tinypic.com/r/ba591/6

This is the log: http://tinypaste.com/1c0ebd91

I suspect the problem has to do with network configuration. I have already disabled the windows firewall where the virtual machine is sitting and in the tp-link router I put the ip of the virtual machine in the DMZ so that it has direct access to the net but still the same problem.

I looked everywhere to see where the problem is but I’m new and I may have overlooked something.

Any help would be appreciated.

Thanks in advance

SkykingOH · July 15, 2012, 6:25pm

You must be overlooking quite a bit. trixbox project has been abandoned for 2 years, uses end of life FreePBX and Asterisk and their repo has issues if you try and update. I don’t know why they leave the site up.

The FreePBX distro (maintained by some of the folks that author FreePBX) and PBX in a flash are two current distro’s.

asofan · July 15, 2012, 8:37pm

How about elastix? is it a current distro?

I just tried the above steps with elastix and facing the same problem.

SkykingOH · July 15, 2012, 8:41pm

Elastix is not “stock” FreePBX, I don’t know much about it other that it has a lot of additional software related to enterprise messaging and such that most folks don’t need and if they do I would probably recommend they run it on a different server or instance.

If you have Elastix installed and it is doing what you want and you know how to use it I would not worry about what distro you are running right now.

Clearly your trunk is not setup correctly, need log data from /var/log/asterisk/full when the call is rejected to confirm. Please post with [code]tag[/code] so the log is legible.

SkykingOH · July 15, 2012, 8:45pm

Update, found your log. That should be fine. The fact it is ringing and not rejecting the call is useful.

Turn off the dial plan debug and turn on sip debug.

core set verbose 0
sip set debug on

Don’t forget to turn off when done.

asofan · July 15, 2012, 11:11pm

Ok,

I downloaded and installed FreePBX distro and followed the installation steps in the official website.

I like the interface, but the problem still remains.

Here is the log of the call:


[2012-07-16 02:03:32] VERBOSE[2824] netsock2.c: == Using SIP RTP TOS bits 184

[2012-07-16 02:03:32] VERBOSE[2824] netsock2.c: == Using SIP RTP CoS mark 5

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [00967736683202@from-internal:1] Macro(“SIP/508-00000009”, “user-callerid,LIMIT,”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/508-00000009”, “AMPUSER=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/508-00000009”, “0?report”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/508-00000009”, “1?Set(REALCALLERIDNUM=508)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/508-00000009”, “AMPUSER=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/508-00000009”, “AMPUSERCIDNAME=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/508-00000009”, “0?report”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/508-00000009”, “AMPUSERCID=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/508-00000009”, “CALLERID(all)=“508” <508>”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:9] GotoIf(“SIP/508-00000009”, “0?limit”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:10] ExecIf(“SIP/508-00000009”, “1?Set(GROUP(concurrency_limit)=508)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:11] GosubIf(“SIP/508-00000009”, “0?sub-ccss,s,1(from-internal,00967736683202)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:12] ExecIf(“SIP/508-00000009”, “0?Set(CHANNEL(language)=)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/508-00000009”, “1?continue”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (macro-user-callerid,s,26)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/508-00000009”, “CALLERID(number)=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/508-00000009”, “CALLERID(name)=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/508-00000009”, “CHANNEL(language)=en”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [00967736683202@from-internal:2] Set(“SIP/508-00000009”, “MOHCLASS=default”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [00967736683202@from-internal:3] Set(“SIP/508-00000009”, “_NODEST=”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [00967736683202@from-internal:4] Gosub(“SIP/508-00000009”, “sub-record-check,s,1(out,00967736683202,)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/508-00000009”, “1?check”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (sub-record-check,s,6)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/508-00000009”, “__MON_FMT=wav”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:7] GotoIf(“SIP/508-00000009”, “1?next”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (sub-record-check,s,10)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:10] ExecIf(“SIP/508-00000009”, “0?Return()”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:11] GotoIf(“SIP/508-00000009”, “0?out,1”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/508-00000009”, “__REC_STATUS=INITIALIZED”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/508-00000009”, “0?Set(__REC_POLICY_MODE=)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/508-00000009”, “NOW=1342393412”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/508-00000009”, “__DAY=16”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/508-00000009”, “__MONTH=07”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/508-00000009”, “__YEAR=2012”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/508-00000009”, “__TIMESTR=20120716-020332”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/508-00000009”, “__FROMEXTEN=508”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/508-00000009”, “__CALLFILENAME=out-00967736683202-508-20120716-020332-1342393412.9”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@sub-record-check:21] Goto(“SIP/508-00000009”, “out,1”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (sub-record-check,out,1)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [out@sub-record-check:1] ExecIf(“SIP/508-00000009”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [out@sub-record-check:2] GosubIf(“SIP/508-00000009”, “0?record,1(exten,00967736683202,508)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [out@sub-record-check:3] Return(“SIP/508-00000009”, “”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [00967736683202@from-internal:5] Macro(“SIP/508-00000009”, “dialout-trunk,2,00967736683202,”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/508-00000009”, “DIAL_TRUNK=2”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/508-00000009”, “0?sub-pincheck,s,1()”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/508-00000009”, “0?disabletrunk,1”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/508-00000009”, “DIAL_NUMBER=00967736683202”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/508-00000009”, “DIAL_TRUNK_OPTIONS=tr”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/508-00000009”, “OUTBOUND_GROUP=OUT_2”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/508-00000009”, “1?nomax”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (macro-dialout-trunk,s,9)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/508-00000009”, “0?skipoutcid”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/508-00000009”, “DIAL_TRUNK_OPTIONS=”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/508-00000009”, “outbound-callerid,2”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/508-00000009”, “0?Set(CALLERPRES()=)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/508-00000009”, “0?Set(REALCALLERIDNUM=508)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/508-00000009”, “1?normcid”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (macro-outbound-callerid,s,6)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/508-00000009”, “USEROUTCID=”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/508-00000009”, “EMERGENCYCID=”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/508-00000009”, “TRUNKOUTCID=967712306000”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/508-00000009”, “1?trunkcid”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Goto (macro-outbound-callerid,s,12)

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/508-00000009”, “1?Set(CALLERID(all)=967712306000)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/508-00000009”, “0?Set(CALLERID(all)=)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/508-00000009”, “0?Set(CALLERID(all)=)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/508-00000009”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/508-00000009”, “0?sub-flp-2,s,1()”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/508-00000009”, “OUTNUM=00967736683202”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/508-00000009”, “custom=SIP/Poivy”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/508-00000009”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/508-00000009”, “0?Set(DIAL_TRUNK_OPTIONS=M(confirm))”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/508-00000009”, “dialout-trunk-predial-hook,”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/508-00000009”, “”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/508-00000009”, “0?bypass,1”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/508-00000009”, “1?Set(CONNECTEDLINE(num,i)=00967736683202)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/508-00000009”, “1?Set(CONNECTEDLINE(name,i)=CID:967712306000)”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:21] GotoIf(“SIP/508-00000009”, “0?customtrunk”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:22] Dial(“SIP/508-00000009”, “SIP/Poivy/00967736683202,300,”) in new stack

[2012-07-16 02:03:32] VERBOSE[3192] netsock2.c: == Using SIP RTP TOS bits 184

[2012-07-16 02:03:32] VERBOSE[3192] netsock2.c: == Using SIP RTP CoS mark 5

[2012-07-16 02:03:32] VERBOSE[3192] app_dial.c: – Called SIP/Poivy/00967736683202

[2012-07-16 02:04:04] WARNING[2824] chan_sip.c: Retransmission timeout reached on transmission [email protected]:5060 for seqno 102 (Critical Request) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions

Packet timed out after 32000ms with no response

[2012-07-16 02:04:04] WARNING[2824] chan_sip.c: Hanging up call [email protected]:5060 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).

[2012-07-16 02:04:04] VERBOSE[3192] app_dial.c: – SIP/Poivy-0000000a is circuit-busy

[2012-07-16 02:04:04] VERBOSE[3192] app_dial.c: == Everyone is busy/congested at this time (1:0/1/0)

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:23] NoOp(“SIP/508-00000009”, “Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 18”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s@macro-dialout-trunk:24] Goto(“SIP/508-00000009”, “s-CONGESTION,1”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Goto (macro-dialout-trunk,s-CONGESTION,1)

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s-CONGESTION@macro-dialout-trunk:1] Set(“SIP/508-00000009”, “RC=18”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s-CONGESTION@macro-dialout-trunk:2] Goto(“SIP/508-00000009”, “18,1”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Goto (macro-dialout-trunk,18,1)

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [18@macro-dialout-trunk:1] Goto(“SIP/508-00000009”, “s-NOANSWER,1”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Goto (macro-dialout-trunk,s-NOANSWER,1)

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s-NOANSWER@macro-dialout-trunk:1] NoOp(“SIP/508-00000009”, “Dial failed due to trunk reporting NOANSWER - giving up”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s-NOANSWER@macro-dialout-trunk:2] Progress(“SIP/508-00000009”, “”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] pbx.c: – Executing [s-NOANSWER@macro-dialout-trunk:3] Playback(“SIP/508-00000009”, “number-not-answering,noanswer”) in new stack

[2012-07-16 02:04:04] VERBOSE[3192] file.c: – <SIP/508-00000009> Playing ‘number-not-answering.ulaw’ (language ‘en’)

[2012-07-16 02:04:05] VERBOSE[3192] pbx.c: – Executing [s-NOANSWER@macro-dialout-trunk:4] Congestion(“SIP/508-00000009”, “20”) in new stack

[2012-07-16 02:04:05] WARNING[3192] channel.c: Prodding channel ‘SIP/508-00000009’ failed

[2012-07-16 02:04:05] VERBOSE[3192] app_macro.c: == Spawn extension (macro-dialout-trunk, s-NOANSWER, 4) exited non-zero on ‘SIP/508-00000009’ in macro ‘dialout-trunk’

[2012-07-16 02:04:05] VERBOSE[3192] pbx.c: == Spawn extension (from-internal, 00967736683202, 5) exited non-zero on ‘SIP/508-00000009’

[2012-07-16 02:04:05] VERBOSE[3192] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/508-00000009”, “”) in new stack

[2012-07-16 02:04:05] VERBOSE[3192] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/508-00000009’

dicko · July 16, 2012, 1:35am

Elastix decided about 18 months ago to fork-up FreePBX, much as TrickyBox did a few years ago, they currently are running to catchup with 2.8, so far not so well. due to the changes in 2.9, never mind 2.10 and without a “We fu&^ed up” apology to Phillipe at al then I suggest they are possibly dead in the water.

I was intimately involved with the development of that distribution, several of my peers left a while ago.

There where many reasons, but we are past that, I believe their concept of reuse of cdr’s and userfields will prevent the move to Asterisk 10 and FreePBX past 2.8, It is a shame but lime green died for obvious reasons and bright orange still think they can go it alone, I await a total capitulation of Elastix to “higher powers”. if not so offered then a painful collapse of said distro.

dicko

SkykingOH · July 16, 2012, 2:19am

Well, since you did not follow the directions and use the code tags
(it is one of the reasons we request it other than the fact that it is really hard to read the variable pitch fonts) I have to wonder what other steps you missed.

You get some credit for using the wrong format for the code tag I guess,
but the devil is in the details and you
need to pay attention when setting up these systems.

Did you go to SIP settings and setup NAT?

The log shows that you don’t have RTP continuity so the audio is timing out:

[2012-07-16 02:04:04] WARNING[2824] chan_sip.c: Retransmission timeout reached on transmission [email protected]:5060 for seqno 102 (Critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions

Remember the audio has to have a two way path. NAT is tricky with SIP.

asofan · July 16, 2012, 4:21pm

Ok I tried the two commands you suggested above and here is the outcome:


[2012-07-16 19:16:45] VERBOSE[2849] chan_sip.c: -- Registered SIP '508' at 192.168.1.101:59312
[2012-07-16 19:17:17] VERBOSE[2849] netsock2.c: == Using SIP RTP TOS bits 184
[2012-07-16 19:17:17] VERBOSE[2849] netsock2.c: == Using SIP RTP CoS mark 5
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [00967737606070@from-internal:1] Macro("SIP/508-0000000a", "user-callerid,LIMIT,") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/508-0000000a", "AMPUSER=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/508-0000000a", "0?report") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/508-0000000a", "1?Set(REALCALLERIDNUM=508)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/508-0000000a", "AMPUSER=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/508-0000000a", "AMPUSERCIDNAME=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/508-0000000a", "0?report") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/508-0000000a", "AMPUSERCID=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:8] Set("SIP/508-0000000a", "CALLERID(all)="508" <508>") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:9] GotoIf("SIP/508-0000000a", "0?limit") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:10] ExecIf("SIP/508-0000000a", "1?Set(GROUP(concurrency_limit)=508)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:11] GosubIf("SIP/508-0000000a", "0?sub-ccss,s,1(from-internal,00967737606070)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:12] ExecIf("SIP/508-0000000a", "0?Set(CHANNEL(language)=)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/508-0000000a", "1?continue") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (macro-user-callerid,s,26)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:26] Set("SIP/508-0000000a", "CALLERID(number)=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:27] Set("SIP/508-0000000a", "CALLERID(name)=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-user-callerid:28] Set("SIP/508-0000000a", "CHANNEL(language)=en") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [00967737606070@from-internal:2] Set("SIP/508-0000000a", "MOHCLASS=default") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [00967737606070@from-internal:3] Set("SIP/508-0000000a", "_NODEST=") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [00967737606070@from-internal:4] Gosub("SIP/508-0000000a", "sub-record-check,s,1(out,00967737606070,)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/508-0000000a", "1?check") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (sub-record-check,s,6)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/508-0000000a", "__MON_FMT=wav") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:7] GotoIf("SIP/508-0000000a", "1?next") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (sub-record-check,s,10)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("SIP/508-0000000a", "0?Return()") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:11] GotoIf("SIP/508-0000000a", "0?out,1") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/508-0000000a", "__REC_STATUS=INITIALIZED") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/508-0000000a", "0?Set(__REC_POLICY_MODE=)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:14] Set("SIP/508-0000000a", "NOW=1342455437") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:15] Set("SIP/508-0000000a", "__DAY=16") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:16] Set("SIP/508-0000000a", "__MONTH=07") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:17] Set("SIP/508-0000000a", "__YEAR=2012") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:18] Set("SIP/508-0000000a", "__TIMESTR=20120716-191717") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:19] Set("SIP/508-0000000a", "__FROMEXTEN=508") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:20] Set("SIP/508-0000000a", "__CALLFILENAME=out-00967737606070-508-20120716-191717-1342455437.10") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@sub-record-check:21] Goto("SIP/508-0000000a", "out,1") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (sub-record-check,out,1)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [out@sub-record-check:1] ExecIf("SIP/508-0000000a", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [out@sub-record-check:2] GosubIf("SIP/508-0000000a", "0?record,1(exten,00967737606070,508)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [out@sub-record-check:3] Return("SIP/508-0000000a", "") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [00967737606070@from-internal:5] Macro("SIP/508-0000000a", "dialout-trunk,2,00967737606070,") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/508-0000000a", "DIAL_TRUNK=2") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/508-0000000a", "0?sub-pincheck,s,1()") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/508-0000000a", "0?disabletrunk,1") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/508-0000000a", "DIAL_NUMBER=00967737606070") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/508-0000000a", "DIAL_TRUNK_OPTIONS=tr") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/508-0000000a", "OUTBOUND_GROUP=OUT_2") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/508-0000000a", "1?nomax") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (macro-dialout-trunk,s,9)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/508-0000000a", "0?skipoutcid") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/508-0000000a", "DIAL_TRUNK_OPTIONS=") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/508-0000000a", "outbound-callerid,2") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/508-0000000a", "0?Set(CALLERPRES()=)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/508-0000000a", "0?Set(REALCALLERIDNUM=508)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/508-0000000a", "1?normcid") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (macro-outbound-callerid,s,6)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/508-0000000a", "USEROUTCID=") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/508-0000000a", "EMERGENCYCID=") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/508-0000000a", "TRUNKOUTCID=967712306000") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/508-0000000a", "1?trunkcid") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Goto (macro-outbound-callerid,s,12)
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/508-0000000a", "1?Set(CALLERID(all)=967712306000)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/508-0000000a", "0?Set(CALLERID(all)=)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/508-0000000a", "0?Set(CALLERID(all)=)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/508-0000000a", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/508-0000000a", "0?sub-flp-2,s,1()") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/508-0000000a", "OUTNUM=00967737606070") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/508-0000000a", "custom=SIP/Poivy") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/508-0000000a", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/508-0000000a", "0?Set(DIAL_TRUNK_OPTIONS=M(confirm))") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:17] Macro("SIP/508-0000000a", "dialout-trunk-predial-hook,") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/508-0000000a", "") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/508-0000000a", "0?bypass,1") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/508-0000000a", "1?Set(CONNECTEDLINE(num,i)=00967737606070)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/508-0000000a", "1?Set(CONNECTEDLINE(name,i)=CID:967712306000)") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/508-0000000a", "0?customtrunk") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:22] Dial("SIP/508-0000000a", "SIP/Poivy/00967737606070,300,") in new stack
[2012-07-16 19:17:17] VERBOSE[3190] netsock2.c: == Using SIP RTP TOS bits 184
[2012-07-16 19:17:17] VERBOSE[3190] netsock2.c: == Using SIP RTP CoS mark 5
[2012-07-16 19:17:17] VERBOSE[3190] app_dial.c: -- Called SIP/Poivy/00967737606070
[2012-07-16 19:17:49] VERBOSE[3190] app_dial.c: -- SIP/Poivy-0000000b is circuit-busy
[2012-07-16 19:17:49] VERBOSE[3190] app_dial.c: == Everyone is busy/congested at this time (1:0/1/0)
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:23] NoOp("SIP/508-0000000a", "Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 0") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s@macro-dialout-trunk:24] Goto("SIP/508-0000000a", "s-CONGESTION,1") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Goto (macro-dialout-trunk,s-CONGESTION,1)
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s-CONGESTION@macro-dialout-trunk:1] Set("SIP/508-0000000a", "RC=0") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s-CONGESTION@macro-dialout-trunk:2] Goto("SIP/508-0000000a", "0,1") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Goto (macro-dialout-trunk,0,1)
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [0@macro-dialout-trunk:1] Goto("SIP/508-0000000a", "continue,1") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Goto (macro-dialout-trunk,continue,1)
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [continue@macro-dialout-trunk:1] GotoIf("SIP/508-0000000a", "1?noreport") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Goto (macro-dialout-trunk,continue,3)
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [continue@macro-dialout-trunk:3] NoOp("SIP/508-0000000a", "TRUNK Dial failed due to CONGESTION HANGUPCAUSE: 0 - failing through to other trunks") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [continue@macro-dialout-trunk:4] Set("SIP/508-0000000a", "CALLERID(number)=508") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [00967737606070@from-internal:6] Macro("SIP/508-0000000a", "outisbusy,") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s@macro-outisbusy:1] Progress("SIP/508-0000000a", "") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s@macro-outisbusy:2] GotoIf("SIP/508-0000000a", "0?emergency,1") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s@macro-outisbusy:3] GotoIf("SIP/508-0000000a", "0?intracompany,1") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] pbx.c: -- Executing [s@macro-outisbusy:4] Playback("SIP/508-0000000a", "all-circuits-busy-now&pls-try-call-later, noanswer") in new stack
[2012-07-16 19:17:49] VERBOSE[3190] file.c: --  Playing 'all-circuits-busy-now.ulaw' (language 'en')
[2012-07-16 19:17:49] WARNING[2849] chan_sip.c: Retransmission timeout reached on transmission [email protected]:5060 for seqno 102 (Critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 32004ms with no response
[2012-07-16 19:17:51] VERBOSE[3190] file.c: --  Playing 'pls-try-call-later.ulaw' (language 'en')
[2012-07-16 19:17:53] VERBOSE[3190] pbx.c: -- Executing [s@macro-outisbusy:5] Congestion("SIP/508-0000000a", "20") in new stack
[2012-07-16 19:17:53] WARNING[3190] channel.c: Prodding channel 'SIP/508-0000000a' failed
[2012-07-16 19:17:53] VERBOSE[3190] app_macro.c: == Spawn extension (macro-outisbusy, s, 5) exited non-zero on 'SIP/508-0000000a' in macro 'outisbusy'
[2012-07-16 19:17:53] VERBOSE[3190] pbx.c: == Spawn extension (from-internal, 00967737606070, 6) exited non-zero on 'SIP/508-0000000a'
[2012-07-16 19:17:53] VERBOSE[3190] pbx.c: -- Executing [h@from-internal:1] Hangup("SIP/508-0000000a", "") in new stack
[2012-07-16 19:17:53] VERBOSE[3190] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/508-0000000a'

How can I setup NAT with SIP?

SkykingOH · July 16, 2012, 5:03pm

You ran those commands? Where? Did you get any errors? Did you notice that you still have dial plan debug and no SIP messages posted?

As far as SIP and NAT, have you searched for previous articles? NAT is one of the most often discussed topics and is now easily addresses with SIP settings module.

asofan · July 17, 2012, 1:50pm

Sorry SkyKing,

I didn’t realize that I had to re-enter those commands once I restarted freepbx.

Here is the log :


[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: 
<--- SIP read from UDP:192.168.1.101:51543 --->
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-6215b97cb10bde1a-1---d8754z-;rport
Max-Forwards: 70
Contact: 
To: 
From: "508";tag=1a6aeb04
Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
Content-Type: application/sdp
Supported: replaces
User-Agent: 3CXPhone 6.0.20943.0
Content-Length: 408
v=0

o=3cxVCE 366547740 260319015 IN IP4 192.168.1.101

s=3cxVCE Audio Call

c=IN IP4 192.168.1.101

t=0 0

m=audio 40030 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-15

a=ptime:20

a=sendrecv

m=video 40028 RTP/AVP 34

c=IN IP4 192.168.1.101

a=rtpmap:34 H263/90000

a=fmtp:34 QCIF=1;CIF=1;SQCIF=1;CIF4=1;

a=sendrecv

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

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: — (13 headers 18 lines) —

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Sending to 192.168.1.101:51543 (NAT)

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Using INVITE request as basis request - NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found peer ‘508’ for ‘508’ from 192.168.1.101:51543

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c:

<— Reliably Transmitting (no NAT) to 192.168.1.101:51543 —>

SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-6215b97cb10bde1a-1—d8754z-;received=192.168.1.101;rport=51543

From: "508"sip:[email protected]:5060;tag=1a6aeb04

To: sip:[email protected]:5060;tag=as300100af

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 1 INVITE

Server: FPBX-2.10.1(1.8.13.0)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="0a030e25"

Content-Length: 0
<------------>

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Scheduling destruction of SIP dialog ‘NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.’ in 6720 ms (Method: INVITE)

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c:

<— SIP read from UDP:192.168.1.101:51543 —>

ACK sip:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-6215b97cb10bde1a-1—d8754z-;rport

Max-Forwards: 70

To: sip:[email protected]:5060;tag=as300100af

From: "508"sip:[email protected]:5060;tag=1a6aeb04

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 1 ACK

Content-Length: 0
<------------->

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: — (8 headers 0 lines) —

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c:

<— SIP read from UDP:192.168.1.101:51543 —>

INVITE sip:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-507c532612351e01-1—d8754z-;rport

Max-Forwards: 70

Contact: sip:[email protected]:51543;rinstance=145542dd98b73be4

To: sip:[email protected]:5060

From: "508"sip:[email protected]:5060;tag=1a6aeb04

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 2 INVITE

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE

Content-Type: application/sdp

Supported: replaces

User-Agent: 3CXPhone 6.0.20943.0

Authorization: Digest username=“508”,realm=“asterisk”,nonce=“0a030e25”,uri=“sip:[email protected]:5060”,response=“2bacb0a3be15f7d365435632185a7950”,algorithm=MD5

Content-Length: 408
v=0

o=3cxVCE 366547740 260319015 IN IP4 192.168.1.101

s=3cxVCE Audio Call

c=IN IP4 192.168.1.101

t=0 0

m=audio 40030 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-15

a=ptime:20

a=sendrecv

m=video 40028 RTP/AVP 34

c=IN IP4 192.168.1.101

a=rtpmap:34 H263/90000

a=fmtp:34 QCIF=1;CIF=1;SQCIF=1;CIF4=1;

a=sendrecv

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

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: — (14 headers 18 lines) —

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Sending to 192.168.1.101:51543 (no NAT)

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Using INVITE request as basis request - NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found peer ‘508’ for ‘508’ from 192.168.1.101:51543

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found RTP audio format 0

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found RTP audio format 8

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found RTP audio format 3

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found RTP audio format 101

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found audio description format PCMU for ID 0

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found audio description format PCMA for ID 8

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found audio description format GSM for ID 3

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found audio description format telephone-event for ID 101

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found RTP video format 34

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Found video description format H263 for ID 34

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Capabilities: us - 0x10e (gsm|ulaw|alaw|g729), peer - audio=0xe (gsm|ulaw|alaw)/video=0x80000 (h263)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw)

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Peer audio RTP is at port 192.168.1.101:40030

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: Looking for 00967711532426 in from-internal (domain 192.168.1.103)

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c: list_route: hop: sip:[email protected]:51543;rinstance=145542dd98b73be4

[2012-07-17 13:42:29] VERBOSE[2884] chan_sip.c:

<— Transmitting (no NAT) to 192.168.1.101:51543 —>

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-507c532612351e01-1—d8754z-;received=192.168.1.101;rport=51543

From: "508"sip:[email protected]:5060;tag=1a6aeb04

To: sip:[email protected]:5060

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 2 INVITE

Server: FPBX-2.10.1(1.8.13.0)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Length: 0
<------------>

[2012-07-17 13:42:29] VERBOSE[3232] chan_sip.c: Audio is at 16858

[2012-07-17 13:42:29] VERBOSE[3232] chan_sip.c: Adding codec 0x4 (ulaw) to SDP

[2012-07-17 13:42:29] VERBOSE[3232] chan_sip.c: Adding codec 0x8 (alaw) to SDP

[2012-07-17 13:42:29] VERBOSE[3232] chan_sip.c: Adding codec 0x2 (gsm) to SDP

[2012-07-17 13:42:29] VERBOSE[3232] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP

[2012-07-17 13:42:29] VERBOSE[3232] chan_sip.c: Reliably Transmitting (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:42:30] VERBOSE[2884] chan_sip.c: Retransmitting #1 (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:42:31] VERBOSE[2884] chan_sip.c: Retransmitting #2 (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:42:33] VERBOSE[2884] chan_sip.c: Retransmitting #3 (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:42:34] VERBOSE[2884] chan_sip.c:

<— SIP read from UDP:192.168.1.101:51543 —>
<------------->

[2012-07-17 13:42:37] VERBOSE[2884] chan_sip.c: Retransmitting #4 (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:42:42] VERBOSE[2884] chan_sip.c: Really destroying SIP dialog ‘OGZjNDcxOTFmNWQyYjk0OWQzNmUxZjNmYTJjYTM3ZDU.’ Method: REGISTER

[2012-07-17 13:42:45] VERBOSE[2884] chan_sip.c: Retransmitting #5 (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:43:01] VERBOSE[2884] chan_sip.c: Retransmitting #6 (NAT) to 77.72.169.131:5060:

INVITE sip:[email protected] SIP/2.0

Via: SIP/2.0/UDP 109.200.166.102:5060;branch=z9hG4bK73823a2c;rport

Max-Forwards: 70

From: “967712306000” sip:[email protected];tag=as7a9555c7

To: sip:[email protected]

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.10.1(1.8.13.0)

Date: Tue, 17 Jul 2012 10:42:29 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 290
v=0

o=root 1802681376 1802681376 IN IP4 109.200.166.102

s=Asterisk PBX 1.8.13.0

c=IN IP4 109.200.166.102

t=0 0

m=audio 16858 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=ptime:20

a=sendrecv

[2012-07-17 13:43:01] VERBOSE[2884] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 32000 ms (Method: INVITE)

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 32000 ms (Method: INVITE)

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c: Audio is at 19676

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c: Adding codec 0x4 (ulaw) to SDP

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c: Adding codec 0x8 (alaw) to SDP

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c: Adding codec 0x2 (gsm) to SDP

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP

[2012-07-17 13:43:01] VERBOSE[3232] chan_sip.c:

<— Transmitting (no NAT) to 192.168.1.101:51543 —>

SIP/2.0 183 Session Progress

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-507c532612351e01-1—d8754z-;received=192.168.1.101;rport=51543

From: "508"sip:[email protected]:5060;tag=1a6aeb04

To: sip:[email protected]:5060;tag=as4b4f3d70

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 2 INVITE

Server: FPBX-2.10.1(1.8.13.0)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 308
v=0

o=root 1762514991 1762514991 IN IP4 192.168.1.103

s=Asterisk PBX 1.8.13.0

c=IN IP4 192.168.1.103

t=0 0

m=audio 19676 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=ptime:20

a=sendrecv

m=video 0 RTP/AVP 34
<------------>

[2012-07-17 13:43:01] WARNING[2884] chan_sip.c: Retransmission timeout reached on transmission [email protected]:5060 for seqno 102 (Critical Request) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions

Packet timed out after 32003ms with no response

[2012-07-17 13:43:01] VERBOSE[2884] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: INVITE

[2012-07-17 13:43:04] VERBOSE[2884] chan_sip.c:

<— SIP read from UDP:192.168.1.101:51543 —>
<------------->

[2012-07-17 13:43:05] VERBOSE[3232] chan_sip.c:

<— Reliably Transmitting (no NAT) to 192.168.1.101:51543 —>

SIP/2.0 503 Service Unavailable

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-507c532612351e01-1—d8754z-;received=192.168.1.101;rport=51543

From: "508"sip:[email protected]:5060;tag=1a6aeb04

To: sip:[email protected]:5060;tag=as4b4f3d70

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 2 INVITE

Server: FPBX-2.10.1(1.8.13.0)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Length: 0
<------------>

[2012-07-17 13:43:05] WARNING[3232] channel.c: Prodding channel ‘SIP/508-00000008’ failed

[2012-07-17 13:43:05] VERBOSE[2884] chan_sip.c:

<— SIP read from UDP:192.168.1.101:51543 —>

ACK sip:[email protected]:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-507c532612351e01-1—d8754z-;rport

Max-Forwards: 70

To: sip:[email protected]:5060;tag=as4b4f3d70

From: "508"sip:[email protected]:5060;tag=1a6aeb04

Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.

CSeq: 2 ACK

Content-Length: 0
<------------->

[2012-07-17 13:43:05] VERBOSE[2884] chan_sip.c: — (8 headers 0 lines) —

[2012-07-17 13:43:05] VERBOSE[2884] chan_sip.c: Really destroying SIP dialog ‘NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.’ Method: ACK

SkykingOH · July 17, 2012, 4:53pm

The phone is stopping to respond to RTP, as if the firewall timed out the xlate.

2012-07-17 13:43:01] WARNING[2884] chan_sip.c: Retransmission timeout reached on transmission [email protected]:5060 for seqno 102 (Critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions

The the other phone comes back with a SIP 503

2012-07-17 13:43:05] VERBOSE[3232] chan_sip.c:
<--- Reliably Transmitting (no NAT) to 192.168.1.101:51543 --->
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 192.168.1.101:51543;branch=z9hG4bK-d8754z-507c532612351e01-1---d8754z-;received=192.168.1.101;rport=51543
From: "508";tag=1a6aeb04
To: ;tag=as4b4f3d70
Call-ID: NDYyNjgzYjFkODY2NTU1MGFjMjc0MGI1ODM2ZjMwNjM.
CSeq: 2 INVITE
Server: FPBX-2.10.1(1.8.13.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0