[Gelöst] Benötige Hilfe für eingehende Anrufe

akoetzle

Neuer User
Mitglied seit
23 Sep 2013
Beiträge
8
Punkte für Reaktionen
0
Punkte
0
Hallo,

ich bin Neuling bzgl. Asterisk / FreePBX. Ich habe folgende Konfiguration :
Telekom IP <--> Fritzbox 7490 <--> FreePBX

Ich habe nach div. Suchen die Einstellungen für den Trunk nach https://www.luxgruppe.de/tech/?p=261 durchgeführt. Ich habe zwei interne Nebenstellen angelegt (1000 und 1001). Über eine Gigaset N510 IP Pro habe ich die beiden Leitungen an die PBX registriert.
Interne Gespräche funktionieren. Nach Extern ist ebenfalls kein Problem. Wenn ich jedoch von Extern anrufe, sehe ich kurz das Telefon "aufleuchten" (es zeigt kurz das Klingelsymbol). Danach springt es wieder in den normalen Modus. Am anderen Ende höre ich nur 7 oder 8 kurze hohe Töne schnell hintereinander. Sonst nichts. Nach ca. 20s wird aufgelegt.

Kann mir jemand hier Unterstützung geben. Ich habe natürlich die Suchfunktion genutzt aber entweder die falschen Kriterien verwendet oder es hat nicht geholfen. Ich habe auch beide internen Leitungen verwendet mit selbem Ergebnis.

Hier die Konfig vom Trunk:
Code:
Peer: Name: tr-fb620
host=192.168.5.1
username=620
secret=++++++
type=peer
qualify=yes
dtmfmode=rfc2833
fromdomain=fritz.box
fromuser=620
disallow=all
allow=alaw&ulaw&g726
insecure=port,invite

User: Name: 620
context=from-trunk
secret=++++++
type=user
insecure=port,invite
fromdomain=fritz.box
disallow=all
allow=alaw&ulaw&g726

Auszug aus dem CLI Log:

Code:
...
    -- Goto (macro-dial-one,s,43)
    -- Executing [s@macro-dial-one:43] Macro("SIP/tr-fb620-00000002", "dialout-one-predial-hook,") in new stack
    -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/tr-fb620-00000002", "") in new stack
    -- Executing [s@macro-dial-one:44] Dial("SIP/tr-fb620-00000002", "SIP/1001,20,Ttr") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called SIP/1001
  == Spawn extension (macro-dial-one, s, 44) exited non-zero on 'SIP/tr-fb620-00000002' in macro 'dial-one'
  == Spawn extension (macro-exten-vm, s, 16) exited non-zero on 'SIP/tr-fb620-00000002' in macro 'exten-vm'
  == Spawn extension (ext-local, 1001, 2) exited non-zero on 'SIP/tr-fb620-00000002'
    -- Executing [h@ext-local:1] Macro("SIP/tr-fb620-00000002", "hangupcall,") in new stack
    -- Executing [s@macro-hangupcall:1] ExecIf("SIP/tr-fb620-00000002", "0?Set(CDR(recordingfile)=.wav)") in new stack
    -- Executing [s@macro-hangupcall:2] GotoIf("SIP/tr-fb620-00000002", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] Hangup("SIP/tr-fb620-00000002", "") in new stack
  == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/tr-fb620-00000002' in macro 'hangupcall'
  == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/tr-fb620-00000002'

Man sieht ja auch, das die Nebenstelle angerufen wird.....
Falls noch mehr Info benötigt wird, dann bitte ich um kurze Info. Danke


Danke für eure Hilfe
 
Zuletzt bearbeitet:
PS: Ich habe es heute mit einem Zoiper-Client auf dem Handy versucht. Dort ist es ebenso. Es klingelt kurz auf dem Zoiper, dann ist es wieder vorbei. (Entgangener Anruf wird angezeigt?!?!)
Der Anrufer hört nur die kurzen schnellen hohen Töne ....
 
Schaut eigentlich nicht schlecht aus. Mach mal sip set debug peer 1001 und probier noch mal anzurufen. Nicht erschrecken, da kommt viiiiiel Text, aber vielleicht kann man da was erkennen woran es scheitert.
 
@rentier-s
OK. Das habe ich gemacht. Als Anfänger bin ich aber etwas überfordert mit dem Log.

Code:
[2015-07-27 13:47:26] VERBOSE[1994] chan_sip.c: Reliably Transmitting (no NAT) to IP_ADR_N510:5060:
OPTIONS sip:1000@IP_ADR_N510:5060 SIP/2.0
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK474216dd
Max-Forwards: 70
From: "Unknown" <sip:Unknown@IP_ADR_PBX>;tag=as2caa67a9
To: <sip:1000@IP_ADR_N510:5060>
Contact: <sip:Unknown@IP_ADR_PBX:5060>
Call-ID: 0ac46316084dbfb67d9b3bcd1e42c320@IP_ADR_PBX:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-12.0.74(11.18.0)
Date: Mon, 27 Jul 2015 11:47:26 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2015-07-27 13:47:26] VERBOSE[1994] chan_sip.c:
<--- SIP read from UDP:IP_ADR_N510:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK474216dd
From: "Unknown" <sip:Unknown@IP_ADR_PBX>;tag=as2caa67a9
To: <sip:1000@IP_ADR_N510:5060>;tag=ar3baa76a8
Call-ID: 0ac46316084dbfb67d9b3bcd1e42c320@IP_ADR_PBX:5060
CSeq: 102 OPTIONS
Supported: replaces
User-Agent: N510 IP PRO/42.210.00.000.000
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, SUBSCRIBE, NOTIFY, REFER
Accept: application/sdp,application/dtmf-relay,application/simple-message-summary,message/sipfrag
Accept-Encoding: identity
Accept-Language: en
Content-Length: 0

<------------->
[2015-07-27 13:47:26] VERBOSE[1994] chan_sip.c: --- (13 headers 0 lines) ---
[2015-07-27 13:47:26] VERBOSE[1994] chan_sip.c: Really destroying SIP dialog '0ac46316084dbfb67d9b3bcd1e42c320@IP_ADR_PBX:5060' Method: OPTIONS
[2015-07-27 13:47:34] VERBOSE[1994][C-0000000b] netsock2.c: == Using SIP RTP TOS bits 184
[2015-07-27 13:47:34] VERBOSE[1994][C-0000000b] netsock2.c: == Using SIP RTP CoS mark 5
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk-sip-tr-fb620:1] Set("SIP/tr-fb620-00000014", "GROUP()=OUT_2") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk-sip-tr-fb620:2] Goto("SIP/tr-fb620-00000014", "from-trunk,620,1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (from-trunk,620,1)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:1] Set("SIP/tr-fb620-00000014", "__FROM_DID=620") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:2] Gosub("SIP/tr-fb620-00000014", "sub-record-check,s,1(in,620,dontcare)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/tr-fb620-00000014", "0?initialized") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:2] Set("SIP/tr-fb620-00000014", "__REC_STATUS=INITIALIZED") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:3] Set("SIP/tr-fb620-00000014", "NOW=1437997654") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:4] Set("SIP/tr-fb620-00000014", "__DAY=27") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:5] Set("SIP/tr-fb620-00000014", "__MONTH=07") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/tr-fb620-00000014", "__YEAR=2015") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:7] Set("SIP/tr-fb620-00000014", "__TIMESTR=20150727-134734") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:8] Set("SIP/tr-fb620-00000014", "__FROMEXTEN=unknown") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:9] Set("SIP/tr-fb620-00000014", "__MON_FMT=wav") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/tr-fb620-00000014", "Recordings initialized") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/tr-fb620-00000014", "0?Set(ARG3=dontcare)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/tr-fb620-00000014", "REC_POLICY_MODE_SAVE=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/tr-fb620-00000014", "0?Set(REC_STATUS=NO)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/tr-fb620-00000014", "2?checkaction") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,s,17)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/tr-fb620-00000014", "1?sub-record-check,in,1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,in,1)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [in@sub-record-check:1] NoOp("SIP/tr-fb620-00000014", "Inbound Recording Check to 620") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [in@sub-record-check:2] Set("SIP/tr-fb620-00000014", "FROMEXTEN=unknown") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [in@sub-record-check:3] ExecIf("SIP/tr-fb620-00000014", "11?Set(FROMEXTEN=TEL_EXT)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [in@sub-record-check:4] Gosub("SIP/tr-fb620-00000014", "recordcheck,1(dontcare,in,620)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/tr-fb620-00000014", "Starting recording check against dontcare") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/tr-fb620-00000014", "dontcare") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,recordcheck,3)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:3] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [in@sub-record-check:5] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:3] Gosub("SIP/tr-fb620-00000014", "app-blacklist-check,s,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@app-blacklist-check:1] GotoIf("SIP/tr-fb620-00000014", "0?blacklisted") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@app-blacklist-check:2] Set("SIP/tr-fb620-00000014", "CALLED_BLACKLIST=1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@app-blacklist-check:3] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:4] Set("SIP/tr-fb620-00000014", "CDR(did)=620") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:5] ExecIf("SIP/tr-fb620-00000014", "1 ?Set(CALLERID(name)=TEL_EXT)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:6] Set("SIP/tr-fb620-00000014", "CHANNEL(musicclass)=default") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:7] Set("SIP/tr-fb620-00000014", "__MOHCLASS=default") in new stack
[2015-07-27 13:47:34] WARNING[17178][C-0000000b] func_channel.c: Unknown or unavailable item requested: 'reversecharge'
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:8] GotoIf("SIP/tr-fb620-00000014", "0?macro-hangupcall") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:9] Set("SIP/tr-fb620-00000014", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:10] Set("SIP/tr-fb620-00000014", "CALLERPRES()=allowed_not_screened") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [620@from-trunk:11] Goto("SIP/tr-fb620-00000014", "from-did-direct,1001,1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (from-did-direct,1001,1)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [1001@from-did-direct:1] GotoIf("SIP/tr-fb620-00000014", "1?ext-local,1001,1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (ext-local,1001,1)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [1001@ext-local:1] Set("SIP/tr-fb620-00000014", "__RINGTIMER=20") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [1001@ext-local:2] Macro("SIP/tr-fb620-00000014", "exten-vm,1001,1001,0,0,0") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/tr-fb620-00000014", "user-callerid,") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/tr-fb620-00000014", "TOUCH_MONITOR=1437997654.20") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:2] Set("SIP/tr-fb620-00000014", "AMPUSER=TEL_EXT") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/tr-fb620-00000014", "0?report") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf("SIP/tr-fb620-00000014", "1?Set(REALCALLERIDNUM=TEL_EXT)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/tr-fb620-00000014", "AMPUSER=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/tr-fb620-00000014", "0?limit") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/tr-fb620-00000014", "AMPUSERCIDNAME=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf("SIP/tr-fb620-00000014", "1?report") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-user-callerid,s,16)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf("SIP/tr-fb620-00000014", "0?continue") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:17] ExecIf("SIP/tr-fb620-00000014", "1?Set(__CALLEE_ACCOUNCODE=2001)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:18] Set("SIP/tr-fb620-00000014", "__TTL=64") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:19] GotoIf("SIP/tr-fb620-00000014", "1?continue") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-user-callerid,s,30)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:30] Set("SIP/tr-fb620-00000014", "CALLERID(number)=TEL_EXT") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:31] Set("SIP/tr-fb620-00000014", "CALLERID(name)=TEL_EXT") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:32] Set("SIP/tr-fb620-00000014", "CDR(cnum)=TEL_EXT") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:33] Set("SIP/tr-fb620-00000014", "CDR(cnam)=TEL_EXT") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-user-callerid:34] Set("SIP/tr-fb620-00000014", "CHANNEL(language)=en") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:2] Set("SIP/tr-fb620-00000014", "RingGroupMethod=none") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:3] Set("SIP/tr-fb620-00000014", "__EXTTOCALL=1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:4] Set("SIP/tr-fb620-00000014", "__PICKUPMARK=1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:5] Set("SIP/tr-fb620-00000014", "RT=20") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:6] ExecIf("SIP/tr-fb620-00000014", "0?Macro(vm,1001,DIRECTDIAL,)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:7] ExecIf("SIP/tr-fb620-00000014", "0?MacroExit()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:8] Gosub("SIP/tr-fb620-00000014", "sub-record-check,s,1(exten,1001,dontcare)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/tr-fb620-00000014", "11?initialized") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,s,10)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/tr-fb620-00000014", "Recordings initialized") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/tr-fb620-00000014", "0?Set(ARG3=dontcare)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/tr-fb620-00000014", "REC_POLICY_MODE_SAVE=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/tr-fb620-00000014", "0?Set(REC_STATUS=NO)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/tr-fb620-00000014", "5?checkaction") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,s,17)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/tr-fb620-00000014", "1?sub-record-check,exten,1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,exten,1)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:1] NoOp("SIP/tr-fb620-00000014", "Exten Recording Check between TEL_EXT and 1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:2] Set("SIP/tr-fb620-00000014", "CALLTYPE=external") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:3] ExecIf("SIP/tr-fb620-00000014", "0?Set(CALLTYPE=)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:4] Set("SIP/tr-fb620-00000014", "CALLEE=no") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:5] ExecIf("SIP/tr-fb620-00000014", "0?Set(CALLEE=dontcare)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:6] GotoIf("SIP/tr-fb620-00000014", "1?callee") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,exten,11)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:11] Gosub("SIP/tr-fb620-00000014", "recordcheck,1(no,external,1001)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/tr-fb620-00000014", "Starting recording check against no") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/tr-fb620-00000014", "no") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (sub-record-check,recordcheck,12)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:12] Set("SIP/tr-fb620-00000014", "__REC_POLICY_MODE=NO") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [recordcheck@sub-record-check:13] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [exten@sub-record-check:12] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:9] GotoIf("SIP/tr-fb620-00000014", "1?macrodial") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-exten-vm,s,15)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:15] GosubIf("SIP/tr-fb620-00000014", "0?clrheader,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-exten-vm:16] Macro("SIP/tr-fb620-00000014", "dial-one,20,Ttr,1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:1] Set("SIP/tr-fb620-00000014", "DEXTEN=1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:2] Set("SIP/tr-fb620-00000014", "DIALSTATUS_CW=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:3] GosubIf("SIP/tr-fb620-00000014", "0?screen,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:4] GosubIf("SIP/tr-fb620-00000014", "0?cf,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:5] GotoIf("SIP/tr-fb620-00000014", "1?skip1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-dial-one,s,8)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:8] GotoIf("SIP/tr-fb620-00000014", "0?nodial") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:9] GotoIf("SIP/tr-fb620-00000014", "0?continue") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:10] Set("SIP/tr-fb620-00000014", "EXTHASCW=ENABLED") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:11] GotoIf("SIP/tr-fb620-00000014", "0?next1:cwinusebusy") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-dial-one,s,23)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:23] GotoIf("SIP/tr-fb620-00000014", "1?next3:continue") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-dial-one,s,24)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:24] ExecIf("SIP/tr-fb620-00000014", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:25] GotoIf("SIP/tr-fb620-00000014", "0?nodial") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:26] GosubIf("SIP/tr-fb620-00000014", "1?dstring,1():dlocal,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:1] Set("SIP/tr-fb620-00000014", "DSTRING=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("SIP/tr-fb620-00000014", "DEVICES=1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/tr-fb620-00000014", "0?Return()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/tr-fb620-00000014", "0?Set(DEVICES=001)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:5] Set("SIP/tr-fb620-00000014", "LOOPCNT=1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("SIP/tr-fb620-00000014", "ITER=1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("SIP/tr-fb620-00000014", "THISDIAL=SIP/1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/tr-fb620-00000014", "1?zap2dahdi,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/tr-fb620-00000014", "0?Return()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/tr-fb620-00000014", "NEWDIAL=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/tr-fb620-00000014", "LOOPCNT2=1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/tr-fb620-00000014", "ITER2=1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/tr-fb620-00000014", "THISPART2=SIP/1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/tr-fb620-00000014", "0?Set(THISPART2=DAHDI/1001)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/tr-fb620-00000014", "NEWDIAL=SIP/1001&") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/tr-fb620-00000014", "ITER2=2") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/tr-fb620-00000014", "0?begin2") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/tr-fb620-00000014", "THISDIAL=SIP/1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:9] GotoIf("SIP/tr-fb620-00000014", "1?doset") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-dial-one,dstring,13)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:13] Set("SIP/tr-fb620-00000014", "DSTRING=SIP/1001&") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:14] Set("SIP/tr-fb620-00000014", "ITER=2") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:15] GotoIf("SIP/tr-fb620-00000014", "0?begin") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:16] ExecIf("SIP/tr-fb620-00000014", "0?Return()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:17] Set("SIP/tr-fb620-00000014", "DSTRING=SIP/1001") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [dstring@macro-dial-one:18] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("SIP/tr-fb620-00000014", "0?nodial") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("SIP/tr-fb620-00000014", "0?skiptrace") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:29] GosubIf("SIP/tr-fb620-00000014", "1?ctset,1():ctclear,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [ctset@macro-dial-one:1] Set("SIP/tr-fb620-00000014", "DB(CALLTRACE/1001)=TEL_EXT") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [ctset@macro-dial-one:2] Return("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:30] Set("SIP/tr-fb620-00000014", "D_OPTIONS=Ttr") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("SIP/tr-fb620-00000014", "0?SIPAddHeader(Alert-Info: )") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("SIP/tr-fb620-00000014", "0?SIPAddHeader()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("SIP/tr-fb620-00000014", "1?Set(CHANNEL(musicclass)=default)") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("SIP/tr-fb620-00000014", "0?qwait,1()") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:35] Set("SIP/tr-fb620-00000014", "__CWIGNORE=") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:36] Set("SIP/tr-fb620-00000014", "__KEEPCID=TRUE") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:37] GotoIf("SIP/tr-fb620-00000014", "0?usegoto,1") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:38] GotoIf("SIP/tr-fb620-00000014", "1?godial") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-dial-one,s,43)
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:43] Macro("SIP/tr-fb620-00000014", "dialout-one-predial-hook,") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-dial-one:44] Dial("SIP/tr-fb620-00000014", "SIP/1001,20,Ttr") in new stack
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] netsock2.c: == Using SIP RTP TOS bits 184
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] netsock2.c: == Using SIP RTP CoS mark 5
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Audio is at 19274
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Adding codec 100004 (alaw) to SDP
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Adding codec 100003 (ulaw) to SDP
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Adding codec 100002 (gsm) to SDP
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Adding codec 100011 (g726) to SDP
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] chan_sip.c: Reliably Transmitting (no NAT) to IP_ADR_N510:5060:
INVITE sip:1001@IP_ADR_N510:5060 SIP/2.0
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK73bb53c7
Max-Forwards: 70
From: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>;tag=as62015720
To: <sip:1001@IP_ADR_N510:5060>
Contact: <sip:TEL_EXT@IP_ADR_PBX:5060>
Call-ID: 2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060
CSeq: 102 INVITE
User-Agent: FPBX-12.0.74(11.18.0)
Date: Mon, 27 Jul 2015 11:47:34 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
P-Asserted-Identity: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>
Content-Type: application/sdp
Content-Length: 316

v=0
o=root 1876418300 1876418300 IN IP4 IP_ADR_PBX
s=Asterisk PBX 11.18.0
c=IN IP4 IP_ADR_PBX
t=0 0
m=audio 19274 RTP/AVP 8 0 3 111 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
[2015-07-27 13:47:34] VERBOSE[17178][C-0000000b] app_dial.c: -- Called SIP/1001
[2015-07-27 13:47:34] VERBOSE[1994] chan_sip.c:
<--- SIP read from UDP:IP_ADR_N510:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK73bb53c7
From: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>;tag=as62015720
To: <sip:1001@IP_ADR_N510:5060>;tag=818420201
Call-ID: 2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060
CSeq: 102 INVITE
Contact: <sip:1001@IP_ADR_N510:5060>
User-Agent: N510 IP PRO/42.210.00.000.000
Content-Length: 0

<------------->
[2015-07-27 13:47:34] VERBOSE[1994] chan_sip.c: --- (9 headers 0 lines) ---
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] chan_sip.c: Scheduling destruction of SIP dialog '2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060' in 6400 ms (Method: INVITE)
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] chan_sip.c: Reliably Transmitting (no NAT) to IP_ADR_N510:5060:
CANCEL sip:1001@IP_ADR_N510:5060 SIP/2.0
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK73bb53c7
Max-Forwards: 70
From: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>;tag=as62015720
To: <sip:1001@IP_ADR_N510:5060>
Call-ID: 2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060
CSeq: 102 CANCEL
User-Agent: FPBX-12.0.74(11.18.0)
Content-Length: 0


---
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] chan_sip.c: Scheduling destruction of SIP dialog '2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060' in 6400 ms (Method: INVITE)
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] app_macro.c: == Spawn extension (macro-dial-one, s, 44) exited non-zero on 'SIP/tr-fb620-00000014' in macro 'dial-one'
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] app_macro.c: == Spawn extension (macro-exten-vm, s, 16) exited non-zero on 'SIP/tr-fb620-00000014' in macro 'exten-vm'
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: == Spawn extension (ext-local, 1001, 2) exited non-zero on 'SIP/tr-fb620-00000014'
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [h@ext-local:1] Macro("SIP/tr-fb620-00000014", "hangupcall,") in new stack
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("SIP/tr-fb620-00000014", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("SIP/tr-fb620-00000014", "1?theend") in new stack
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: -- Goto (macro-hangupcall,s,4)
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/tr-fb620-00000014", "") in new stack
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/tr-fb620-00000014' in macro 'hangupcall'
[2015-07-27 13:47:35] VERBOSE[17178][C-0000000b] pbx.c: == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/tr-fb620-00000014'
[2015-07-27 13:47:35] VERBOSE[1994] chan_sip.c:
<--- SIP read from UDP:IP_ADR_N510:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK73bb53c7
From: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>;tag=as62015720
To: <sip:1001@IP_ADR_N510:5060>;tag=818420201
Call-ID: 2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060
CSeq: 102 CANCEL
Contact: <sip:1001@IP_ADR_N510:5060>
User-Agent: N510 IP PRO/42.210.00.000.000
Content-Length: 0

<------------->
[2015-07-27 13:47:35] VERBOSE[1994] chan_sip.c: --- (9 headers 0 lines) ---
[2015-07-27 13:47:35] VERBOSE[1994] chan_sip.c:
<--- SIP read from UDP:IP_ADR_N510:5060 --->
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK73bb53c7
From: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>;tag=as62015720
To: <sip:1001@IP_ADR_N510:5060>;tag=818420201
Call-ID: 2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060
CSeq: 102 INVITE
Contact: <sip:1001@IP_ADR_N510:5060>
User-Agent: N510 IP PRO/42.210.00.000.000
Content-Length: 0

<------------->
[2015-07-27 13:47:35] VERBOSE[1994] chan_sip.c: --- (9 headers 0 lines) ---
[2015-07-27 13:47:35] VERBOSE[1994][C-0000000b] chan_sip.c: Transmitting (no NAT) to IP_ADR_N510:5060:
ACK sip:1001@IP_ADR_N510:5060 SIP/2.0
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK73bb53c7
Max-Forwards: 70
From: "TEL_EXT" <sip:TEL_EXT@IP_ADR_PBX>;tag=as62015720
To: <sip:1001@IP_ADR_N510:5060>;tag=818420201
Contact: <sip:TEL_EXT@IP_ADR_PBX:5060>
Call-ID: 2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060
CSeq: 102 ACK
User-Agent: FPBX-12.0.74(11.18.0)
Content-Length: 0


---
[2015-07-27 13:47:35] VERBOSE[1994][C-0000000b] chan_sip.c: Scheduling destruction of SIP dialog '2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060' in 6400 ms (Method: INVITE)
[2015-07-27 13:47:37] VERBOSE[1994] chan_sip.c: Reliably Transmitting (no NAT) to IP_ADR_N510:5060:
OPTIONS sip:1001@IP_ADR_N510:5060 SIP/2.0
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK1af82f0c
Max-Forwards: 70
From: "Unknown" <sip:Unknown@IP_ADR_PBX>;tag=as433297ca
To: <sip:1001@IP_ADR_N510:5060>
Contact: <sip:Unknown@IP_ADR_PBX:5060>
Call-ID: 66bc5bc911b610581a374ff7390ae25d@IP_ADR_PBX:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-12.0.74(11.18.0)
Date: Mon, 27 Jul 2015 11:47:37 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


---
[2015-07-27 13:47:37] VERBOSE[1994] chan_sip.c:
<--- SIP read from UDP:IP_ADR_N510:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP IP_ADR_PBX:5060;branch=z9hG4bK1af82f0c
From: "Unknown" <sip:Unknown@IP_ADR_PBX>;tag=as433297ca
To: <sip:1001@IP_ADR_N510:5060>;tag=ar522386ba
Call-ID: 66bc5bc911b610581a374ff7390ae25d@IP_ADR_PBX:5060
CSeq: 102 OPTIONS
Supported: replaces
User-Agent: N510 IP PRO/42.210.00.000.000
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, SUBSCRIBE, NOTIFY, REFER
Accept: application/sdp,application/dtmf-relay,application/simple-message-summary,message/sipfrag
Accept-Encoding: identity
Accept-Language: en
Content-Length: 0

<------------->
[2015-07-27 13:47:37] VERBOSE[1994] chan_sip.c: --- (13 headers 0 lines) ---
[2015-07-27 13:47:37] VERBOSE[1994] chan_sip.c: Really destroying SIP dialog '66bc5bc911b610581a374ff7390ae25d@IP_ADR_PBX:5060' Method: OPTIONS
[2015-07-27 13:47:41] VERBOSE[1994] chan_sip.c: Really destroying SIP dialog '2df1981b29daa0d97e601e2753d7b4ff@IP_ADR_PBX:5060' Method: INVITE

Kannst du da nochmal drüberschauen, ob dir was auffällt?

Danke
 
Naja, es fällt auf, dass der Anruf nach einer Sekunde wieder abgebrochen wird, allerdings ohne Fehler auf dieser Strecke. Das Problem muss also weiter vorne liegen.

Gibt es in der Fritzbox im System-Log eine Meldung wie Telefonie mit 620 nicht erfolgreich...? Ansonsten bräuchten wir noch das Debug von der anderen Seite, also sip set debug peer 620 (vorher ggf. sip set debug off).
 
Also erstmal Danke für die Unterstützung....

Ich habe das mal getestet. Was ich sehen kann:

CSeq: 94 CANCEL
Reason: SIP; cause=200; text="Call completed elsewhere"
Max-Forwards: 70

Ich habe folgenden Verdacht: An der FB ist an der ISDN Seite noch die zu ersetzende alte TK Anlage dran. Ich habe zwar die Rufnummer auf das IP-Telefon geleitet, aber ich vermute, dass die FB irgendwie den Anruf auch an die ISDN Anlage weitergibt.

Ist das denkbar?
 
Ja, ist es. Die Fritzbox signalisiert grundsätzlich alle ankommenden Anrufe auf dem internen S0.

So lange da niemand dran geht, sollte das aber eigentlich kein Cancel auslösen.
 
Genau. Das war es. In meiner Auerswald war die Nummer noch eingetragen, aber nicht zugewiesen. Nummer raus und es funktioniert.

Danke...
 
Holen Sie sich 3CX - völlig kostenlos!
Verbinden Sie Ihr Team und Ihre Kunden Telefonie Livechat Videokonferenzen

Gehostet oder selbst-verwaltet. Für bis zu 10 Nutzer dauerhaft kostenlos. Keine Kreditkartendetails erforderlich. Ohne Risiko testen.

3CX
Für diese E-Mail-Adresse besteht bereits ein 3CX-Konto. Sie werden zum Kundenportal weitergeleitet, wo Sie sich anmelden oder Ihr Passwort zurücksetzen können, falls Sie dieses vergessen haben.