-2

Inbound caller (1636) calls a sipstation direct dial to my phone on my desk.

Cellphone sounds like fast busy but then desk phone rings.

Cant connect the call. then when desk phone hangs up It rings again (to no avail as well) sometimes 3 or more phantom calls.

Asterisk Log : 

    [2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/fpbx-1-f23bc5a3-0000011f", "THISDIAL=SIP/311") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/fpbx-1-f23bc5a3-0000011f", "") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [dstring@macro-dial-one:9] Set("SIP/fpbx-1-f23bc5a3-0000011f", "DSTRING=SIP/311&") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [dstring@macro-dial-one:10] Set("SIP/fpbx-1-f23bc5a3-0000011f", "ITER=2") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [dstring@macro-dial-one:11] GotoIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?begin") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [dstring@macro-dial-one:12] Set("SIP/fpbx-1-f23bc5a3-0000011f", "DSTRING=SIP/311") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [dstring@macro-dial-one:13] Return("SIP/fpbx-1-f23bc5a3-0000011f", "") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?nodial") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?skiptrace") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:29] GosubIf("SIP/fpbx-1-f23bc5a3-0000011f", "1?ctset,1():ctclear,1()") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [ctset@macro-dial-one:1] Set("SIP/fpbx-1-f23bc5a3-0000011f", "DB(CALLTRACE/311)=+17274531636") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [ctset@macro-dial-one:2] Return("SIP/fpbx-1-f23bc5a3-0000011f", "") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:30] Set("SIP/fpbx-1-f23bc5a3-0000011f", "D_OPTIONS=tr") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?SIPAddHeader(Alert-Info: )") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?SIPAddHeader()") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?Set(CHANNEL(musicclass)=)") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?qwait,1()") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:35] Set("SIP/fpbx-1-f23bc5a3-0000011f", "__CWIGNORE=") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:36] Set("SIP/fpbx-1-f23bc5a3-0000011f", "__KEEPCID=TRUE") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:37] GotoIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?usegoto,1") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:38] GotoIf("SIP/fpbx-1-f23bc5a3-0000011f", "1?godial") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Goto (macro-dial-one,s,42)
[2012-08-01 09:08:01] VERBOSE[7036] pbx.c: -- Executing [s@macro-dial-one:42] Dial("SIP/fpbx-1-f23bc5a3-0000011f", "SIP/311,15,tr") in new stack
[2012-08-01 09:08:01] VERBOSE[7036] netsock2.c: == Using SIP RTP TOS bits 184
[2012-08-01 09:08:01] VERBOSE[7036] netsock2.c: == Using SIP RTP CoS mark 5
[2012-08-01 09:08:01] VERBOSE[7036] app_dial.c: -- Called SIP/311
[2012-08-01 09:08:06] VERBOSE[7035] pbx.c: -- Executing [h@from-did-direct:1] Macro("SIP/fpbx-2-f23bc5a3-0000011d", "hangupcall,") in new stack
[2012-08-01 09:08:11] WARNING[3921] chan_sip.c: Retransmission timeout reached on transmission 3e57de11239b49f10930969c7e23d1ca@50.58.42.81:5060 for seqno 102 (Critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 9983ms with no response
[2012-08-01 09:08:11] WARNING[3921] chan_sip.c: Hanging up call 3e57de11239b49f10930969c7e23d1ca@50.58.42.81:5060 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2012-08-01 09:08:11] VERBOSE[7036] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2012-08-01 09:08:11] VERBOSE[7035] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/fpbx-2-f23bc5a3-0000011d", "1?theend") in new stack
[2012-08-01 09:08:11] VERBOSE[7035] pbx.c: -- Goto (macro-hangupcall,s,3)
[2012-08-01 09:08:11] VERBOSE[7035] pbx.c: -- Executing [s@macro-hangupcall:3] ExecIf("SIP/fpbx-2-f23bc5a3-0000011d", "0?Set(CDR(recordingfile)=)") in new stack
[2012-08-01 09:08:11] VERBOSE[7035] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/fpbx-2-f23bc5a3-0000011d", "") in new stack
[2012-08-01 09:08:11] VERBOSE[7035] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/fpbx-2-f23bc5a3-0000011d' in macro 'hangupcall'
[2012-08-01 09:08:11] VERBOSE[7035] pbx.c: == Spawn extension (from-did-direct, h, 1) exited non-zero on 'SIP/fpbx-2-f23bc5a3-0000011d'
[2012-08-01 09:08:16] VERBOSE[7036] pbx.c: -- Executing [h@from-did-direct:1] Macro("SIP/fpbx-1-f23bc5a3-0000011f", "hangupcall,") in new stack
[2012-08-01 09:08:16] VERBOSE[7036] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/fpbx-1-f23bc5a3-0000011f", "1?theend") in new stack
[2012-08-01 09:08:16] VERBOSE[7036] pbx.c: -- Goto (macro-hangupcall,s,3)
[2012-08-01 09:08:16] VERBOSE[7036] pbx.c: -- Executing [s@macro-hangupcall:3] ExecIf("SIP/fpbx-1-f23bc5a3-0000011f", "0?Set(CDR(recordingfile)=)") in new stack
[2012-08-01 09:08:16] VERBOSE[7036] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/fpbx-1-f23bc5a3-0000011f", "") in new stack
[2012-08-01 09:08:16] VERBOSE[7036] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/fpbx-1-f23bc5a3-0000011f' in macro 'hangupcall'
[2012-08-01 09:08:16] VERBOSE[7036] pbx.c: == Spawn extension (from-did-direct, h, 1) exited non-zero on 'SIP/fpbx-1-f23bc5a3-0000011f'
[2012-08-01 09:08:18] WARNING[3921] chan_sip.c: Retransmission timeout reached on transmission 9679a4d7-569e-1230-28bb-40404edf54cf for seqno 31584440 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2012-08-01 09:08:23] WARNING[3921] chan_sip.c: Retransmission timeout reached on transmission 9836b680-569e-1230-28bb-40404edf54cf for seqno 31584441 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2012-08-01 09:09:21] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk2.phonebooth.net'
[2012-08-01 09:09:26] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk1.phonebooth.net'
[2012-08-01 09:11:16] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk2.phonebooth.net'
[2012-08-01 09:11:21] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk1.phonebooth.net'
[2012-08-01 09:11:45] VERBOSE[7033] asterisk.c: -- Remote UNIX connection disconnected
[2012-08-01 09:13:11] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk2.phonebooth.net'
[2012-08-01 09:13:16] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk1.phonebooth.net'
[2012-08-01 09:15:06] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk2.phonebooth.net'
[2012-08-01 09:15:11] VERBOSE[3921] dnsmgr.c: > doing dnsmgr_lookup for 'trunk1.phonebooth.net'
[2012-08-01 09:15:21] VERBOSE[3921] netsock2.c: == Using SIP RTP TOS bits 184
[2012-08-01 09:15:21] VERBOSE[3921] netsock2.c: == Using SIP RTP CoS mark 5
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [7272225497@from-pstn:1] Set("SIP/fpbx-2-f23bc5a3-00000121", "__FROM_DID=7272225497") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [7272225497@from-pstn:2] Set("SIP/fpbx-2-f23bc5a3-00000121", "CDR(did)=7272225497") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [7272225497@from-pstn:3] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0 ?Set(CALLERID(name)=+17274531636)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [7272225497@from-pstn:4] Set("SIP/fpbx-2-f23bc5a3-00000121", "__CALLINGPRES_SV=prohib_not_screened") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [7272225497@from-pstn:5] Set("SIP/fpbx-2-f23bc5a3-00000121", "CALLERPRES()=allowed_not_screened") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [7272225497@from-pstn:6] Goto("SIP/fpbx-2-f23bc5a3-00000121", "from-did-direct,311,1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (from-did-direct,311,1)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [311@from-did-direct:1] Set("SIP/fpbx-2-f23bc5a3-00000121", "__RINGTIMER=15") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [311@from-did-direct:2] Macro("SIP/fpbx-2-f23bc5a3-00000121", "exten-vm,311,311,0,0,0") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/fpbx-2-f23bc5a3-00000121", "user-callerid,") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/fpbx-2-f23bc5a3-00000121", "AMPUSER=+17274531636") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?report") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "1?Set(REALCALLERIDNUM=+17274531636)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/fpbx-2-f23bc5a3-00000121", "AMPUSER=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/fpbx-2-f23bc5a3-00000121", "AMPUSERCIDNAME=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?report") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-user-callerid,s,11)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:11] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?continue") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:12] Set("SIP/fpbx-2-f23bc5a3-00000121", "__TTL=64") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?continue") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-user-callerid,s,24)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:24] Set("SIP/fpbx-2-f23bc5a3-00000121", "CALLERID(number)=+17274531636") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:25] Set("SIP/fpbx-2-f23bc5a3-00000121", "CALLERID(name)=+17274531636") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-user-callerid:26] Set("SIP/fpbx-2-f23bc5a3-00000121", "CHANNEL(language)=en") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:2] Set("SIP/fpbx-2-f23bc5a3-00000121", "RingGroupMethod=none") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:3] Set("SIP/fpbx-2-f23bc5a3-00000121", "__EXTTOCALL=311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:4] Set("SIP/fpbx-2-f23bc5a3-00000121", "__PICKUPMARK=311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:5] Set("SIP/fpbx-2-f23bc5a3-00000121", "RT=15") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:6] Gosub("SIP/fpbx-2-f23bc5a3-00000121", "sub-record-check,s,1(exten,311,)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?check") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (sub-record-check,s,6)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/fpbx-2-f23bc5a3-00000121", "__MON_FMT=wav") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:7] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?next") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (sub-record-check,s,10)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Return()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:11] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?exten,1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/fpbx-2-f23bc5a3-00000121", "__REC_STATUS=INITIALIZED") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Set(__REC_POLICY_MODE=)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:14] Set("SIP/fpbx-2-f23bc5a3-00000121", "NOW=1343826921") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:15] Set("SIP/fpbx-2-f23bc5a3-00000121", "__DAY=01") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:16] Set("SIP/fpbx-2-f23bc5a3-00000121", "__MONTH=08") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:17] Set("SIP/fpbx-2-f23bc5a3-00000121", "__YEAR=2012") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:18] Set("SIP/fpbx-2-f23bc5a3-00000121", "__TIMESTR=20120801-091521") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:19] Set("SIP/fpbx-2-f23bc5a3-00000121", "__FROMEXTEN=+17274531636") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:20] Set("SIP/fpbx-2-f23bc5a3-00000121", "__CALLFILENAME=exten-311-+17274531636-20120801-091521-1343826921.481") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@sub-record-check:21] Goto("SIP/fpbx-2-f23bc5a3-00000121", "exten,1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (sub-record-check,exten,1)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [exten@sub-record-check:1] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?callee") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [exten@sub-record-check:2] Set("SIP/fpbx-2-f23bc5a3-00000121", "__REC_POLICY_MODE=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [exten@sub-record-check:3] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?caller") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [exten@sub-record-check:4] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?callee") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (sub-record-check,exten,8)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [exten@sub-record-check:8] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "0?record,1(exten,311,+17274531636)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [exten@sub-record-check:9] Return("SIP/fpbx-2-f23bc5a3-00000121", "") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-exten-vm:7] Macro("SIP/fpbx-2-f23bc5a3-00000121", "dial-one,15,tr,311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:1] Set("SIP/fpbx-2-f23bc5a3-00000121", "DEXTEN=311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:2] Set("SIP/fpbx-2-f23bc5a3-00000121", "DIALSTATUS_CW=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:3] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "0?screen,1()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:4] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "0?cf,1()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:5] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?skip1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-dial-one,s,8)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:8] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?nodial") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:9] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?continue") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:10] Set("SIP/fpbx-2-f23bc5a3-00000121", "EXTHASCW=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:11] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?next1:cwinusebusy") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-dial-one,s,12)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:12] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?docfu:skip3") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-dial-one,s,16)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:16] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?next2:continue") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-dial-one,s,17)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:17] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?continue") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-dial-one,s,25)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:25] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?nodial") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:26] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "1?dstring,1():dlocal,1()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:1] Set("SIP/fpbx-2-f23bc5a3-00000121", "DSTRING=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("SIP/fpbx-2-f23bc5a3-00000121", "DEVICES=311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Return()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Set(DEVICES=11)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:5] Set("SIP/fpbx-2-f23bc5a3-00000121", "LOOPCNT=1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("SIP/fpbx-2-f23bc5a3-00000121", "ITER=1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("SIP/fpbx-2-f23bc5a3-00000121", "THISDIAL=SIP/311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "1?zap2dahdi,1()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Return()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/fpbx-2-f23bc5a3-00000121", "NEWDIAL=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/fpbx-2-f23bc5a3-00000121", "LOOPCNT2=1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/fpbx-2-f23bc5a3-00000121", "ITER2=1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/fpbx-2-f23bc5a3-00000121", "THISPART2=SIP/311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Set(THISPART2=DAHDI/311)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/fpbx-2-f23bc5a3-00000121", "NEWDIAL=SIP/311&") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/fpbx-2-f23bc5a3-00000121", "ITER2=2") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?begin2") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/fpbx-2-f23bc5a3-00000121", "THISDIAL=SIP/311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/fpbx-2-f23bc5a3-00000121", "") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:9] Set("SIP/fpbx-2-f23bc5a3-00000121", "DSTRING=SIP/311&") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:10] Set("SIP/fpbx-2-f23bc5a3-00000121", "ITER=2") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:11] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?begin") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:12] Set("SIP/fpbx-2-f23bc5a3-00000121", "DSTRING=SIP/311") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [dstring@macro-dial-one:13] Return("SIP/fpbx-2-f23bc5a3-00000121", "") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?nodial") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?skiptrace") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:29] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "1?ctset,1():ctclear,1()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [ctset@macro-dial-one:1] Set("SIP/fpbx-2-f23bc5a3-00000121", "DB(CALLTRACE/311)=+17274531636") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [ctset@macro-dial-one:2] Return("SIP/fpbx-2-f23bc5a3-00000121", "") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:30] Set("SIP/fpbx-2-f23bc5a3-00000121", "D_OPTIONS=tr") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?SIPAddHeader(Alert-Info: )") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?SIPAddHeader()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("SIP/fpbx-2-f23bc5a3-00000121", "0?Set(CHANNEL(musicclass)=)") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("SIP/fpbx-2-f23bc5a3-00000121", "0?qwait,1()") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:35] Set("SIP/fpbx-2-f23bc5a3-00000121", "__CWIGNORE=") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:36] Set("SIP/fpbx-2-f23bc5a3-00000121", "__KEEPCID=TRUE") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:37] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "0?usegoto,1") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:38] GotoIf("SIP/fpbx-2-f23bc5a3-00000121", "1?godial") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Goto (macro-dial-one,s,42)
[2012-08-01 09:15:21] VERBOSE[7110] pbx.c: -- Executing [s@macro-dial-one:42] Dial("SIP/fpbx-2-f23bc5a3-00000121", "SIP/311,15,tr") in new stack
[2012-08-01 09:15:21] VERBOSE[7110] netsock2.c: == Using SIP RTP TOS bits 184
[2012-08-01 09:15:21] VERBOSE[7110] netsock2.c: == Using SIP RTP CoS mark 5
[2012-08-01 09:15:21] VERBOSE[7110] app_dial.c: -- Called SIP/311
[2012-08-01 09:15:26] VERBOSE[3921] netsock2.c: == Using SIP RTP TOS bits 184
[2012-08-01 09:15:26] VERBOSE[3921] netsock2.c: == Using SIP RTP CoS mark 5
[2012-08-01 09:15:26] NOTICE[3921] chan_sip.c: Peer '604' is now UNREACHABLE! Last qualify: 183
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [7272225497@from-pstn:1] Set("SIP/fpbx-1-f23bc5a3-00000123", "__FROM_DID=7272225497") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [7272225497@from-pstn:2] Set("SIP/fpbx-1-f23bc5a3-00000123", "CDR(did)=7272225497") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [7272225497@from-pstn:3] ExecIf("SIP/fpbx-1-f23bc5a3-00000123", "0 ?Set(CALLERID(name)=+17274531636)") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [7272225497@from-pstn:4] Set("SIP/fpbx-1-f23bc5a3-00000123", "__CALLINGPRES_SV=prohib_not_screened") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [7272225497@from-pstn:5] Set("SIP/fpbx-1-f23bc5a3-00000123", "CALLERPRES()=allowed_not_screened") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [7272225497@from-pstn:6] Goto("SIP/fpbx-1-f23bc5a3-00000123", "from-did-direct,311,1") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Goto (from-did-direct,311,1)
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [311@from-did-direct:1] Set("SIP/fpbx-1-f23bc5a3-00000123", "__RINGTIMER=15") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [311@from-did-direct:2] Macro("SIP/fpbx-1-f23bc5a3-00000123", "exten-vm,311,311,0,0,0") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/fpbx-1-f23bc5a3-00000123", "user-callerid,") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/fpbx-1-f23bc5a3-00000123", "AMPUSER=+17274531636") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/fpbx-1-f23bc5a3-00000123", "0?report") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/fpbx-1-f23bc5a3-00000123", "1?Set(REALCALLERIDNUM=+17274531636)") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/fpbx-1-f23bc5a3-00000123", "AMPUSER=") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/fpbx-1-f23bc5a3-00000123", "AMPUSERCIDNAME=") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/fpbx-1-f23bc5a3-00000123", "1?report") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Goto (macro-user-callerid,s,11)
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:11] GotoIf("SIP/fpbx-1-f23bc5a3-00000123", "0?continue") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:12] Set("SIP/fpbx-1-f23bc5a3-00000123", "__TTL=64") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/fpbx-1-f23bc5a3-00000123", "1?continue") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Goto (macro-user-callerid,s,24)
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:24] Set("SIP/fpbx-1-f23bc5a3-00000123", "CALLERID(number)=+17274531636") in new stack
[2012-08-01 09:15:26] VERBOSE[7111] pbx.c: -- Executing [s@macro-user-callerid:25] Set("SIP/fpbx-1-f23bc5a3-00000123", "CALLERID(name)=+17274531636") in new stack
Improve this question
4
  • 1
    Did you read the wiki article that was linked in the warning message?
    – Michael Hampton
    Aug 1, 2012 at 17:25
  • Your post is excessively long the limit is 30K - please reduce your log 'snippet' to a sensible length as relevant information may have been lost from the end.
    – user9517
    Aug 1, 2012 at 17:26
  • I did read the article and no it did not help explain this.
    – MarkKGreenway
    Aug 5, 2012 at 16:26
  • It's well clear of the 30k limit which it lets you know as you post the message
    – MarkKGreenway
    Aug 5, 2012 at 16:27

1 Answer 1

Reset to default
2

The important parts of your log are these two WARNING messages:

[2012-08-01 09:08:11] WARNING[3921] chan_sip.c: Retransmission timeout reached on transmission 3e57de11239b49f10930969c7e23d1ca@50.58.42.81:5060 for seqno 102 (Critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 9983ms with no response
[2012-08-01 09:08:11] WARNING[3921] chan_sip.c: Hanging up call 3e57de11239b49f10930969c7e23d1ca@50.58.42.81:5060 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).

This indicates that Asterisk sent a SIP message to your IP phone, but never got a reply back. It was therefore forced to drop the call.

The wiki article linked in the log entry has further information that you can use for debugging this issue. The most likely cause of the problem is a firewall or NAT issue.

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.