ASTERISK-13505: wrong Via-branch-id in CANCEL and ACK

[Home]

Summary: ASTERISK-13505: wrong Via-branch-id in CANCEL and ACK

Reporter: klaus3000 (klaus3000) Labels:

Date Opened: 2009-02-03 09:45:50.000-0600 Date Closed: 2011-06-07 14:08:20

Priority: Minor Regression? No

Status: Closed/Complete Components: Channels/chan_sip/Interoperability

Versions: Frequency of
Occurrence

Related
Issues:

Environment: Attachments:

Description: Hi!

When Asterisk sends a CANCEL it uses a new branch-id instead of using the same as in the INVITE. Then, the ACK to the 487 also uses this wrong branch id. See the trace below.

The strange thing is, that I observe this only on a single Asterisk box.

X-lite Asterisk Asterisk GW
---INVITE-->
-------INVITE---->
----INVITE------>

---CANCEL-->
-----CANCEL------->
-----CANCEL------->

^^^^^^^ ^^^^^^
branch-id correct branch-id wrong

****** ADDITIONAL INFORMATION ******

[Feb 3 16:28:22] VERBOSE[20845] logger.c:
<--- SIP read from 11.11.111184:5160 --->
INVITE sip:+431505640000@11.11.111183 SIP/2.0
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;rport
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>
Contact: <sip:+430000000730101@11.11.111184:5160>
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 INVITE
User-Agent: InnoSIP-app
Max-Forwards: 70
Date: Tue, 03 Feb 2009 15:28:22 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
X-FOOO-USERFIELD:
X-FOOO-AUTOCALL:
X-FOOO-ENUMOUT: 0
X-FOOO-CLIR: 0
X-FOOO-C:
X-FOOO-B: 01505641636
X-FOOO-AN: +430000000730101
X-FOOO-AU: +431234567
Content-Type: application/sdp
Content-Length: 334

v=0
o=root 20776 20776 IN IP4 11.11.111184
s=session
c=IN IP4 11.11.111184
t=0 0
m=audio 17784 RTP/AVP 0 8 97 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
[Feb 3 16:28:22] VERBOSE[20845] logger.c: --- (22 headers 16 lines) ---
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Sending to 11.11.111184 : 5160 (NAT)
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Using INVITE request as basis request - 1beaedf607880745515c57d3059d42a1@11.11.111184
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found peer 'app-asterisk'
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found RTP audio format 0
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found RTP audio format 8
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found RTP audio format 97
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found RTP audio format 3
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found RTP audio format 101
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Peer audio RTP is at port 11.11.111184:17784
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found audio description format PCMU for ID 0
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found audio description format PCMA for ID 8
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found audio description format iLBC for ID 97
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found audio description format GSM for ID 3
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Found audio description format telephone-event for ID 101
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x40e (gsm|ulaw|alaw|ilbc)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw)
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Peer audio RTP is at port 11.11.111184:17784
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Looking for +431505640000 in fromAppAsterisk (domain 11.11.111183)
[Feb 3 16:28:22] VERBOSE[20845] logger.c: list_route: hop: <sip:+430000000730101@11.11.111184:5160>
[Feb 3 16:28:22] VERBOSE[20845] logger.c:
<--- Transmitting (no NAT) to 11.11.111184:5160 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;received=11.11.111184;rport=5160
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 INVITE
User-Agent: InnoSIP-gw
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:+431505640000@11.11.111183>
Content-Length: 0

<------------>
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:1] GotoIf("SIP/5160-090608a0", "1?2:3") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (fromAppAsterisk,+431505640000,2)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:2] Set("SIP/5160-090608a0", "X-FOOO-NOTRUFONKZ=1") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:3] NoOp("SIP/5160-090608a0", "Finish if-fromAppAsterisk-268") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:4] Macro("SIP/5160-090608a0", "setChannelVarsFromAppAsteriskMakro") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:1] Set("SIP/5160-090608a0", "X-FOOO-AN=+430000000730101") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:2] Set("SIP/5160-090608a0", "X-FOOO-AU=+431234567") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:3] Set("SIP/5160-090608a0", "X-FOOO-B=+431505640000") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:4] Set("SIP/5160-090608a0", "X-FOOO-C=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:5] Set("SIP/5160-090608a0", "X-FOOO-CLIR=0") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:6] Set("SIP/5160-090608a0", "X-FOOO-NOTRUF=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:7] Set("SIP/5160-090608a0", "X-FOOO-KURZRUF=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:8] Set("SIP/5160-090608a0", "X-FOOO-NOTRUFONKZ=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:9] Set("SIP/5160-090608a0", "X-FOOO-ENUMOUT=0") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:10] Set("SIP/5160-090608a0", "X-FOOO-AUTOCALL=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:11] Set("SIP/5160-090608a0", "X-FOOO-USERFIELD=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:12] Goto("SIP/5160-090608a0", "13") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (macro-setChannelVarsFromAppAsteriskMakro,s,13)
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Goto
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setChannelVarsFromAppAsteriskMakro:13] NoOp("SIP/5160-090608a0", "End of Macro setChannelVarsFromAppAsteriskMakro-s") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:5] Gosub("SIP/5160-090608a0", "fromAppAsteriskToLocalNumbers|+431505640000|1") in new stack
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Registering request for '+431505640000@ofisNumbers' on behalf of '00:00:00:00:00:00' crc '00000000'
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Found cache expiring in 1117 seconds!
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Found cache expiring in 1117 seconds!
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Found cache expiring in 1117 seconds!
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Found cache expiring in 1127 seconds!
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Found cache expiring in 1127 seconds!
[Feb 3 16:28:22] DEBUG[28222] pbx_dundi.c: Found cache expiring in 1127 seconds!
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsteriskToLocalNumbers:1] Set("SIP/5160-090608a0", "X-FOOO-DUNDIRESULT=") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsteriskToLocalNumbers:2] GotoIf("SIP/5160-090608a0", "1?3:4") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (fromAppAsteriskToLocalNumbers,+431505640000,3)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsteriskToLocalNumbers:3] Return("SIP/5160-090608a0", "") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:6] Gosub("SIP/5160-090608a0", "checkLocalNumberBlocks|+431505640000|1") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Sent into invalid extension '+431505640000' in context 'checkLocalNumberBlocks' on SIP/5160-090608a0
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [i@checkLocalNumberBlocks:1] Return("SIP/5160-090608a0", "") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppAsterisk:7] Goto("SIP/5160-090608a0", "fromAppToPstn|+431505640000|1") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (fromAppToPstn,+431505640000,1)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppToPstn:1] Macro("SIP/5160-090608a0", "setCdrNumsMakro") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:1] Set("SIP/5160-090608a0", "CDR(AN)=+430000000730101") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:2] Set("SIP/5160-090608a0", "CDR(AU)=+431234567") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:3] Set("SIP/5160-090608a0", "CDR(B)=+431505640000") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:4] Set("SIP/5160-090608a0", "CDR(C)=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:5] Set("SIP/5160-090608a0", "CDR(userfield)=") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:6] GotoIf("SIP/5160-090608a0", "0?7:8") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (macro-setCdrNumsMakro,s,8)
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: GotoIf
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:8] NoOp("SIP/5160-090608a0", "Finish if-setCdrNumsMakro-270") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:9] Goto("SIP/5160-090608a0", "10") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (macro-setCdrNumsMakro,s,10)
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Goto
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-setCdrNumsMakro:10] NoOp("SIP/5160-090608a0", "End of Macro setCdrNumsMakro-s") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppToPstn:2] Set("SIP/5160-090608a0", "CDR(BID)=") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppToPstn:3] Set("SIP/5160-090608a0", "CDR(SID)=2") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@fromAppToPstn:4] Goto("SIP/5160-090608a0", "toPstn|+431505640000|1") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn,+431505640000,1)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:1] GotoIf("SIP/5160-090608a0", "0?2:12") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn,+431505640000,12)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:12] NoOp("SIP/5160-090608a0", "Finish if-toPstn-272") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:13] GotoIf("SIP/5160-090608a0", "0?14:15") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn,+431505640000,15)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:15] NoOp("SIP/5160-090608a0", "Finish if-toPstn-276") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:16] Set("SIP/5160-090608a0", "offset=0") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:17] GotoIf("SIP/5160-090608a0", "1?18:31") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn,+431505640000,18)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:18] Macro("SIP/5160-090608a0", "lcrlookup|+431505640000| 0") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-lcrlookup:1] Set("SIP/5160-090608a0", "ext=+431505640000") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-lcrlookup:2] Set("SIP/5160-090608a0", "offset= 0") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-lcrlookup:3] Set("SIP/5160-090608a0", "LCR=barfoo") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:19] Set("SIP/5160-090608a0", "CDR(GWID)=barfoo") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:20] GotoIf("SIP/5160-090608a0", "0?21:22") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn,+431505640000,22)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:22] NoOp("SIP/5160-090608a0", "Finish if-for-toPstn-277-278") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:23] GotoIf("SIP/5160-090608a0", "0?24:27") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn,+431505640000,27)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:27] NoOp("SIP/5160-090608a0", "Finish if-for-toPstn-277-279") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn:28] Gosub("SIP/5160-090608a0", "toPstn_barfoo|+431505640000|1") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:1] Macro("SIP/5160-090608a0", "checkMaxCallsMakro|barfoo|0|1|darilion@foo.at kd@foobar.at") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:1] Set("SIP/5160-090608a0", "groupid=barfoo") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:2] Set("SIP/5160-090608a0", "softlimit=0") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:3] Set("SIP/5160-090608a0", "hardlimit=1") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:4] Set("SIP/5160-090608a0", "email=darilion@foo.at kd@foobar.at") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:5] GotoIf("SIP/5160-090608a0", "0?6:11") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (macro-checkMaxCallsMakro,s,11)
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: GotoIf
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:11] NoOp("SIP/5160-090608a0", "Finish if-checkMaxCallsMakro-288") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:12] GotoIf("SIP/5160-090608a0", "1?13:17") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (macro-checkMaxCallsMakro,s,13)
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: GotoIf
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:13] GotoIf("SIP/5160-090608a0", "1?14:15") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (macro-checkMaxCallsMakro,s,14)
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: GotoIf
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:14] Macro("SIP/5160-090608a0", "emailMakro|Soft-Limit fuer barfoo erreicht!|WARNING: Soft-Limit von 0 fuer barfoo erreicht! go on ...|darilion@foo.at kd@foobar.at") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-emailMakro:1] Set("SIP/5160-090608a0", "subject=Soft-Limit fuer barfoo erreicht!") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-emailMakro:2] Set("SIP/5160-090608a0", "body=WARNING: Soft-Limit von 0 fuer barfoo erreicht! go on ...") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-emailMakro:3] Set("SIP/5160-090608a0", "toemail=darilion@foo.at kd@foobar.at") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-emailMakro:4] TrySystem("SIP/5160-090608a0", "export HOME=/home/asterisk; echo -e "WARNING: Soft-Limit von 0 fuer barfoo erreicht! go on ..." | mutt -s "`hostname -f`: Soft-Limit fuer barfoo erreicht!" darilion@foo.at kd@foobar.at &") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: TrySystem
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Macro
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:15] NoOp("SIP/5160-090608a0", "Finish if-if-checkMaxCallsMakro-290-291") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:16] NoOp("SIP/5160-090608a0", "WARNING: Soft-Limit von 0 fuer barfoo erreicht! go on ...") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:17] NoOp("SIP/5160-090608a0", "Finish if-checkMaxCallsMakro-290") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: NoOp
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [s@macro-checkMaxCallsMakro:18] Set("SIP/5160-090608a0", "GROUP()=barfoo") in new stack
[Feb 3 16:28:22] DEBUG[28222] app_macro.c: Executed application: Set
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:2] SIPAddHeader("SIP/5160-090608a0", "P-Asserted-Identity: <sip:+430000000730101@foobarfo.at>") in new stack
[Feb 3 16:28:22] DEBUG[28222] chan_sip.c: SIP Header added "P-Asserted-Identity: <sip:+430000000730101@foobarfo.at>" as __SIPADDHEADER01
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:3] SIPAddHeader("SIP/5160-090608a0", "P-Preferred-Identity: <sip:+431234567@foobarfo.at>") in new stack
[Feb 3 16:28:22] DEBUG[28222] chan_sip.c: SIP Header added "P-Preferred-Identity: <sip:+431234567@foobarfo.at>" as __SIPADDHEADER02
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:4] GotoIf("SIP/5160-090608a0", "0?5:6") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn_barfoo,+431505640000,6)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:6] NoOp("SIP/5160-090608a0", "Finish if-toPstn_barfoo-281") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:7] GotoIf("SIP/5160-090608a0", "0?8:9") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn_barfoo,+431505640000,9)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:9] NoOp("SIP/5160-090608a0", "Finish if-toPstn_barfoo-282") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:10] GotoIf("SIP/5160-090608a0", "0?11:14") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn_barfoo,+431505640000,14)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:14] GotoIf("SIP/5160-090608a0", "0?15:17") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn_barfoo,+431505640000,17)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:17] GotoIf("SIP/5160-090608a0", "0?18:20") in new stack
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Goto (toPstn_barfoo,+431505640000,20)
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Executing [+431505640000@toPstn_barfoo:20] Dial("SIP/5160-090608a0", "SIP/+431505640000@barfoo") in new stack
[Feb 3 16:28:22] DEBUG[28222] chan_sip.c: Call to peer 'barfoo' is 1 out of 3
[Feb 3 16:28:22] DEBUG[28222] chan_sip.c: Adding SIP Header "P-Preferred-Identity" with content :<sip:+431234567@foobarfo.at>:
[Feb 3 16:28:22] DEBUG[28222] chan_sip.c: Adding SIP Header "P-Asserted-Identity" with content :<sip:+430000000730101@foobarfo.at>:
[Feb 3 16:28:22] VERBOSE[28222] logger.c: Audio is at 11.11.111183 port 14214
[Feb 3 16:28:22] VERBOSE[28222] logger.c: Adding codec 0x4 (ulaw) to SDP
[Feb 3 16:28:22] VERBOSE[28222] logger.c: Adding codec 0x2 (gsm) to SDP
[Feb 3 16:28:22] VERBOSE[28222] logger.c: Adding codec 0x8 (alaw) to SDP
[Feb 3 16:28:22] VERBOSE[28222] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Feb 3 16:28:22] VERBOSE[28222] logger.c: Reliably Transmitting (no NAT) to 222.22.22.22:5060:
INVITE sip:+431505640000@foobarfo.mydom.at SIP/2.0
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2f95836f;rport
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>
Contact: <sip:foobarfo.orig@11.11.111183>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 102 INVITE
User-Agent: InnoSIP-gw
Max-Forwards: 70
Date: Tue, 03 Feb 2009 15:28:22 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
P-Preferred-Identity: <sip:+431234567@foobarfo.at>
P-Asserted-Identity: <sip:+430000000730101@foobarfo.at>
Content-Type: application/sdp
Content-Length: 289

v=0
o=root 20834 20834 IN IP4 11.11.111183
s=session
c=IN IP4 11.11.111183
t=0 0
m=audio 14214 RTP/AVP 0 3 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
[Feb 3 16:28:22] VERBOSE[28222] logger.c: -- Called +431505640000@barfoo
[Feb 3 16:28:22] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2f95836f;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 102 INVITE
Server: barfoo Outbound Proxy
Content-Length: 0

<------------->
[Feb 3 16:28:22] VERBOSE[20845] logger.c: --- (8 headers 0 lines) ---
[Feb 3 16:28:22] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2f95836f;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=t0apNG!OPmIj6y8
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 102 INVITE
Max-Forwards: 69
Supported: replaces
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,SUBSCRIBE,NOTIFY
Record-Route: <sip:222.22.22.22;lr;ftag=as76161974;vsf=xheS5hdA-->
User-Agent: InnoSIP-gw~11.11.111183~11.11.111183
Proxy-Authenticate: Digest realm="foobarfo.mydom.at",nonce="6c9f1cc6b415ded773d559afe28e214c",opaque="3ab2248db29cceac6093ffb7ccabe29a",algorithm=MD5,qop="auth"
Date: Tue, 03 Feb 2009 15:28:22 GMT
P-Preferred-Identity: <sip:+430000000730101@foobarfo.mydom.at>
Remote-Party-ID: <sip:+431234567@os.mydom.at>;party=calling;u=pad

<------------->
[Feb 3 16:28:22] VERBOSE[20845] logger.c: --- (15 headers 0 lines) ---
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Transmitting (no NAT) to 222.22.22.22:5060:
ACK sip:+431505640000@foobarfo.mydom.at SIP/2.0
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2f95836f;rport
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=t0apNG!OPmIj6y8
Contact: <sip:foobarfo.orig@11.11.111183>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 102 ACK
User-Agent: InnoSIP-gw
Max-Forwards: 70
Content-Length: 0

---
[Feb 3 16:28:22] DEBUG[20845] chan_sip.c: Adding SIP Header "P-Preferred-Identity" with content :<sip:+431234567@foobarfo.at>:
[Feb 3 16:28:22] DEBUG[20845] chan_sip.c: Adding SIP Header "P-Asserted-Identity" with content :<sip:+430000000730101@foobarfo.at>:
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Audio is at 11.11.111183 port 14214
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Adding codec 0x4 (ulaw) to SDP
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Adding codec 0x2 (gsm) to SDP
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Adding codec 0x8 (alaw) to SDP
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Feb 3 16:28:22] VERBOSE[20845] logger.c: Reliably Transmitting (no NAT) to 222.22.22.22:5060:
INVITE sip:+431505640000@foobarfo.mydom.at SIP/2.0
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>
Contact: <sip:foobarfo.orig@11.11.111183>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
User-Agent: InnoSIP-gw
Max-Forwards: 70
Proxy-Authorization: removed
Date: Tue, 03 Feb 2009 15:28:22 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
P-Preferred-Identity: <sip:+431234567@foobarfo.at>
P-Asserted-Identity: <sip:+430000000730101@foobarfo.at>
Content-Type: application/sdp
Content-Length: 289

v=0
o=root 20834 20835 IN IP4 11.11.111183
s=session
c=IN IP4 11.11.111183
t=0 0
m=audio 14214 RTP/AVP 0 3 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
[Feb 3 16:28:22] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
Server: barfoo Outbound Proxy
Content-Length: 0

<------------->
[Feb 3 16:28:22] VERBOSE[20845] logger.c: --- (8 headers 0 lines) ---
[Feb 3 16:28:24] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=000423DF6C883706B7D7AE1B821D
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,REFER,NOTIFY,SUBSCRIBE,UPDATE
Content-Length: 191
Content-Type: application/sdp

v=0
o=- 953040559 953040559 IN IP4 193.84.65.198
s=session
c=IN IP4 193.84.65.198
t=0 0
m=audio 10300 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
<------------->
[Feb 3 16:28:24] VERBOSE[20845] logger.c: --- (9 headers 9 lines) ---
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found RTP audio format 0
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found RTP audio format 101
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Peer audio RTP is at port 193.84.65.198:10300
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found audio description format PCMU for ID 0
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found audio description format telephone-event for ID 101
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Peer audio RTP is at port 193.84.65.198:10300
[Feb 3 16:28:24] VERBOSE[28222] logger.c: -- SIP/barfoo-0904f2b0 is making progress passing it to SIP/5160-090608a0
[Feb 3 16:28:24] VERBOSE[28222] logger.c: Audio is at 11.11.111183 port 10110
[Feb 3 16:28:24] VERBOSE[28222] logger.c: Adding codec 0x2 (gsm) to SDP
[Feb 3 16:28:24] VERBOSE[28222] logger.c: Adding codec 0x4 (ulaw) to SDP
[Feb 3 16:28:24] VERBOSE[28222] logger.c: Adding codec 0x8 (alaw) to SDP
[Feb 3 16:28:24] VERBOSE[28222] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Feb 3 16:28:24] VERBOSE[28222] logger.c:
<--- Transmitting (no NAT) to 11.11.111184:5160 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;received=11.11.111184;rport=5160
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>;tag=as70b004dc
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 INVITE
User-Agent: InnoSIP-gw
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:+431505640000@11.11.111183>
Content-Type: application/sdp
Content-Length: 289

v=0
o=root 20834 20834 IN IP4 11.11.111183
s=session
c=IN IP4 11.11.111183
t=0 0
m=audio 10110 RTP/AVP 3 0 8 101
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

<------------>
[Feb 3 16:28:24] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=000423DF6C883706B7D7AE1B821D
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,REFER,NOTIFY,SUBSCRIBE,UPDATE
Content-Length: 191
Content-Type: application/sdp

v=0
o=- 953040559 953040560 IN IP4 193.84.65.198
s=session
c=IN IP4 193.84.65.198
t=0 0
m=audio 10300 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
<------------->
[Feb 3 16:28:24] VERBOSE[20845] logger.c: --- (9 headers 9 lines) ---
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found RTP audio format 0
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found RTP audio format 101
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Peer audio RTP is at port 193.84.65.198:10300
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found audio description format PCMU for ID 0
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Found audio description format telephone-event for ID 101
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Feb 3 16:28:24] VERBOSE[20845] logger.c: Peer audio RTP is at port 193.84.65.198:10300
[Feb 3 16:28:24] VERBOSE[28222] logger.c: -- SIP/barfoo-0904f2b0 is ringing
[Feb 3 16:28:24] VERBOSE[28222] logger.c:
<--- Transmitting (no NAT) to 11.11.111184:5160 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;received=11.11.111184;rport=5160
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>;tag=as70b004dc
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 INVITE
User-Agent: InnoSIP-gw
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:+431505640000@11.11.111183>
Content-Length: 0

<------------>
[Feb 3 16:28:24] VERBOSE[28222] logger.c: -- SIP/barfoo-0904f2b0 is making progress passing it to SIP/5160-090608a0
[Feb 3 16:28:26] VERBOSE[20845] logger.c:
<--- SIP read from 11.11.111184:5160 --->
CANCEL sip:+431505640000@11.11.111183 SIP/2.0
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;rport
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 CANCEL
User-Agent: InnoSIP-app
Max-Forwards: 70
Content-Length: 0

<------------->
[Feb 3 16:28:26] VERBOSE[20845] logger.c: --- (9 headers 0 lines) ---
[Feb 3 16:28:26] VERBOSE[20845] logger.c: Sending to 11.11.111184 : 5160 (NAT)
[Feb 3 16:28:26] VERBOSE[20845] logger.c:
<--- Reliably Transmitting (NAT) to 11.11.111184:5160 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;received=11.11.111184;rport=5160
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>;tag=as70b004dc
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 INVITE
User-Agent: InnoSIP-gw
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0

<------------>
[Feb 3 16:28:26] VERBOSE[20845] logger.c:
<--- Transmitting (NAT) to 11.11.111184:5160 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;received=11.11.111184;rport=5160
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>;tag=as70b004dc
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 CANCEL
User-Agent: InnoSIP-gw
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:+431505640000@11.11.111183>
Content-Length: 0

<------------>
[Feb 3 16:28:26] DEBUG[28222] chan_sip.c: Call to peer 'barfoo' removed from call limit 3
[Feb 3 16:28:26] VERBOSE[28222] logger.c: Scheduling destruction of SIP dialog '2fa501f836c087c2655104200a10a073@foobarfo.mydom.at' in 32000 ms (Method: INVITE)
[Feb 3 16:28:26] VERBOSE[28222] logger.c: Reliably Transmitting (no NAT) to 222.22.22.22:5060:
CANCEL sip:+431505640000@foobarfo.mydom.at SIP/2.0
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK00d4b9a7;rport
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 CANCEL
User-Agent: InnoSIP-gw
Max-Forwards: 70
Content-Length: 0

---
[Feb 3 16:28:26] VERBOSE[28222] logger.c: Scheduling destruction of SIP dialog '2fa501f836c087c2655104200a10a073@foobarfo.mydom.at' in 32000 ms (Method: INVITE)
[Feb 3 16:28:26] VERBOSE[28222] logger.c: == Spawn extension (toPstn_barfoo, +431505640000, 20) exited non-zero on 'SIP/5160-090608a0'
[Feb 3 16:28:26] VERBOSE[20845] logger.c:
<--- SIP read from 11.11.111184:5160 --->
ACK sip:+431505640000@11.11.111183 SIP/2.0
Via: SIP/2.0/UDP 11.11.111184:5160;branch=z9hG4bK5c701c63;rport
From: "+430000000730101" <sip:+430000000730101@11.11.111184:5160>;tag=as5842b568
To: <sip:+431505640000@11.11.111183>;tag=as70b004dc
Contact: <sip:+430000000730101@11.11.111184:5160>
Call-ID: 1beaedf607880745515c57d3059d42a1@11.11.111184
CSeq: 102 ACK
User-Agent: InnoSIP-app
Max-Forwards: 70
Content-Length: 0

<------------->
[Feb 3 16:28:26] VERBOSE[20845] logger.c: --- (10 headers 0 lines) ---
[Feb 3 16:28:26] VERBOSE[20845] logger.c: Really destroying SIP dialog '1beaedf607880745515c57d3059d42a1@11.11.111184' Method: ACK
[Feb 3 16:28:26] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK00d4b9a7;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 CANCEL
Max-Forwards: 69
Record-Route: <sip:222.22.22.22;lr;ftag=as76161974>
User-Agent: InnoSIP-gw

<------------->
[Feb 3 16:28:26] VERBOSE[20845] logger.c: --- (9 headers 0 lines) ---
[Feb 3 16:28:26] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=HBlD_CmgOvKMbsd
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
Max-Forwards: 69
Supported: replaces
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,SUBSCRIBE,NOTIFY
Record-Route: <sip:222.22.22.22;lr;ftag=as76161974;vsf=xheS5hdA-->
User-Agent: InnoSIP-gw~11.11.111183~11.11.111183
History-Info: <sip:+431505640000@foobarfo.mydom.at>;index=1
History-Info: <sip:+431505640000@foobarfo.mydom.at>;index=1.1
Date: Tue, 03 Feb 2009 15:28:22 GMT
P-Preferred-Identity: <sip:+430000000730101@foobarfo.mydom.at>
Remote-Party-ID: <sip:+431234567@os.mydom.at>;party=calling;u=pad

<------------->
[Feb 3 16:28:26] VERBOSE[20845] logger.c: --- (16 headers 0 lines) ---
[Feb 3 16:28:26] VERBOSE[20845] logger.c: Transmitting (no NAT) to 222.22.22.22:5060:
ACK sip:+431505640000@foobarfo.mydom.at SIP/2.0
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK00d4b9a7;rport
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=HBlD_CmgOvKMbsd
Contact: <sip:foobarfo.orig@11.11.111183>
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 ACK
User-Agent: InnoSIP-gw
Max-Forwards: 70
Content-Length: 0

---
[Feb 3 16:28:26] DEBUG[20845] chan_sip.c: Call to peer 'barfoo' removed from call limit 3
[Feb 3 16:28:26] VERBOSE[20845] logger.c: Really destroying SIP dialog '2fa501f836c087c2655104200a10a073@foobarfo.mydom.at' Method: INVITE
[Feb 3 16:28:27] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=HBlD_CmgOvKMbsd
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
Max-Forwards: 69
Supported: replaces
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,SUBSCRIBE,NOTIFY
Record-Route: <sip:222.22.22.22;lr;ftag=as76161974;vsf=xheS5hdA-->
User-Agent: InnoSIP-gw~11.11.111183~11.11.111183
History-Info: <sip:+431505640000@foobarfo.mydom.at>;index=1
History-Info: <sip:+431505640000@foobarfo.mydom.at>;index=1.1
Date: Tue, 03 Feb 2009 15:28:22 GMT
P-Preferred-Identity: <sip:+430000000730101@foobarfo.mydom.at>
Remote-Party-ID: <sip:+431234567@os.mydom.at>;party=calling;u=pad

<------------->
[Feb 3 16:28:27] VERBOSE[20845] logger.c: --- (16 headers 0 lines) ---
[Feb 3 16:28:28] VERBOSE[20845] logger.c:
<--- SIP read from 222.22.22.22:5060 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 11.11.111183:5060;branch=z9hG4bK2c74b753;rport=5060
From: "+430000000730101" <sip:foobarfo.orig@foobarfo.mydom.at>;tag=as76161974
To: <sip:+431505640000@foobarfo.mydom.at>;tag=HBlD_CmgOvKMbsd
Call-ID: 2fa501f836c087c2655104200a10a073@foobarfo.mydom.at
CSeq: 103 INVITE
Max-Forwards: 69
Supported: replaces
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,SUBSCRIBE,NOTIFY
Record-Route: <sip:222.22.22.22;lr;ftag=as76161974;vsf=xheS5hdA-->
User-Agent: InnoSIP-gw~11.11.111183~11.11.111183
History-Info: <sip:+431505640000@foobarfo.mydom.at>;index=1
History-Info: <sip:+431505640000@foobarfo.mydom.at>;index=1.1
Date: Tue, 03 Feb 2009 15:28:22 GMT
P-Preferred-Identity: <sip:+430000000730101@foobarfo.mydom.at>
Remote-Party-ID: <sip:+431234567@os.mydom.at>;party=calling;u=pad

<------------->
[Feb 3 16:28:28] VERBOSE[20845] logger.c: --- (16 headers 0 lines) ---
^C

Comments: By: klaus3000 (klaus3000) 2009-02-06 04:33:48.000-0600

Hi! you can close this one - foxed by Olle in revision 171264
By: Joshua C. Colp (jcolp) 2009-02-06 11:46:57.000-0600

Closed per reporter's comment that this has already been fixed.