Outgoing calls phone disconnects about the first ringback

gwurst · June 7, 2014, 2:06am

I inherited an Asterisk 1.4 system with a bunch of Polycom Soundpoint IP phones that was connected to a T1 line and worked fine. We moved them to a new building, and the T1 was not moved in time so AT&T ran 23 analog lines to the suite. We bought 3 Grandstream GXW4108 gateways to connect the analog lines to the PBX. The config looks a mess but using the basic settings without a SIP account from Grandstream:

grandstream.com/products/gx … terisk.pdf

I at least got all the incoming lines routed to the correct mailboxes. The problem is that outgoing calls are not working with the phones just disconnecting shortly after dialing and hearing the first ringback start. The call goes through but if you answer it it’s just dead air and if you don’t it will continue to ring until going to voicemail.

In the SIP.CONF file I added this section:

[gxw4108b]
type=peer
context=default
host=10.1.1.16
insecure=port

And in the EXTENSIONS.CONF file in the default section I added the following dial plan rules:

exten => _NXXNXXXXXX,1,Dial(SIP/${EXTEN}@gxw4108b)
exten => _1NXXNXXXXXX,1,Dial(SIP/${EXTEN}@gxw4108b)
exten => 911,1,Dial(SIP/${EXTEN}@gxw4108b)

I’m suspecting it has something to do with the settings on the Grandstream box, but I’m unsure. Any ideas?

Thanks,

Greg

david55 · June 7, 2014, 10:29am

You need to provide logs at a sufficient level of detail. The gold standard is: enable full log in logger.conf; core set debug 5; core set verbose 5; sip set debug on.

I wonder, though, if this relates to your having an unrestricted choice of codec and discovering, too late, that you can’t support the one the gateway chooses.

I’m also wondering why you needed insecure=port, but that’s security issue not a connectivity one.

gwurst · June 7, 2014, 2:13pm

I’l change the logging and have someone try it on Monday. Naturally the office is in Indianapolis and I’m 2 hours away and don’t feel like driving back if I can avoid it.

Thanks,

gwurst · June 9, 2014, 1:38pm

Ok, here’s an attempted outgoing phone call. I’ll have to split it into two posts.

[quote][Jun 9 09:34:57] VERBOSE[17023] logger.c: Asterisk Event Logger restarted
[Jun 9 09:34:57] VERBOSE[17023] logger.c: Asterisk Queue Logger restarted
[Jun 9 09:36:20] VERBOSE[3327] logger.c:
<— SIP read from 10.1.2.243:5060 —>
INVITE sip:19375104350@10.1.2.10:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK4279f84f9B3FBDF4
From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
To: sip:19375104350@10.1.2.10;user=phone
CSeq: 1 INVITE
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
Contact: sip:243@10.1.2.243:5060
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267
Accept-Language: en
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 290

v=0
o=- 1168010817 1168010817 IN IP4 10.1.2.243
s=Polycom IP Phone
c=IN IP4 10.1.2.243
t=0 0
a=sendrecv
m=audio 2228 RTP/AVP 9 0 8 18 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:127 telephone-event/8000

<------------->
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 0: INVITE sip:19375104350@10.1.2.10:5060;user=phone SIP/2.0 (56)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK4279f84f9B3FBDF4 (63)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 2: From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542 (52)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.2.10;user=phone (42)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 4: CSeq: 1 INVITE (14)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 5: Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243 (46)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 6: Contact: sip:243@10.1.2.243:5060 (34)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267 (54)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 9: Accept-Language: en (19)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 10: Supported: 100rel,replaces (26)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 11: Allow-Events: talk,hold,conference (34)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 12: Max-Forwards: 70 (16)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 13: Content-Type: application/sdp (29)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 14: Content-Length: 290 (19)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 15: (0)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: v=0 (3)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: o=- 1168010817 1168010817 IN IP4 10.1.2.243 (43)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: s=Polycom IP Phone (18)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: c=IN IP4 10.1.2.243 (19)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: t=0 0 (5)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=sendrecv (10)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: m=audio 2228 RTP/AVP 9 0 8 18 127 (33)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=rtpmap:9 G722/8000 (20)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=fmtp:18 annexb=no (19)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Line: a=rtpmap:127 telephone-event/8000 (33)
[Jun 9 09:36:20] VERBOSE[3327] logger.c: — (15 headers 13 lines) —
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Setting NAT on RTP to Off
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Allocating new SIP dialog for 7491d971-f2ce8406-efb2ecf3@10.1.2.243 - INVITE (With RTP)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Begin: parsing SIP “Supported: 100rel,replaces”
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Found SIP option: -100rel-
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Matched SIP option: 100rel
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Found SIP option: -replaces-
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Matched SIP option: replaces
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Sending to 10.1.2.243 : 5060 (no NAT)
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Using INVITE request as basis request - 7491d971-f2ce8406-efb2ecf3@10.1.2.243
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Setting NAT on RTP to Off
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found user ‘243’
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing session-level SDP o=- 1168010817 1168010817 IN IP4 10.1.2.243… UNSUPPORTED.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing session-level SDP s=Polycom IP Phone… UNSUPPORTED.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing session-level SDP c=IN IP4 10.1.2.243… OK.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing session-level SDP a=sendrecv… OK.
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found RTP audio format 9
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found RTP audio format 0
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found RTP audio format 8
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found RTP audio format 18
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found RTP audio format 127
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found audio description format G722 for ID 9
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000… OK.
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found audio description format PCMU for ID 0
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000… OK.
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found audio description format PCMA for ID 8
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000… OK.
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found audio description format G729 for ID 18
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000… OK.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no… UNSUPPORTED.
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Found audio description format telephone-event for ID 127
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000… OK.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: T38 state changed to 0 on channel
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x110c (ulaw|alaw|g729|g722)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Our T38 capability = (0), peer T38 capability (0), joint T38 capability (0)
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Peer audio RTP is at port 10.1.2.243:2228
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: We’re settling with these formats: 0xc (ulaw|alaw)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Checking SIP call limits for device 243
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Updating call counter for incoming call
[Jun 9 09:36:20] VERBOSE[3327] logger.c: Looking for 19375104350 in local (domain 10.1.2.10)
[Jun 9 09:36:20] DEBUG[3327] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: *** Our native formats are 0x4 (ulaw)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263)
[Jun 9 09:36:20] DEBUG[3327] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: This channel will not be able to handle video.
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: build_route: Contact hop: sip:243@10.1.2.243:5060
[Jun 9 09:36:20] VERBOSE[3327] logger.c: list_route: hop: sip:243@10.1.2.243:5060
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: SIP/243-0000002b: New call is still down… Trying…
[Jun 9 09:36:20] VERBOSE[3327] logger.c:
<— Transmitting (no NAT) to 10.1.2.243:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK4279f84f9B3FBDF4;received=10.1.2.243
From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
To: sip:19375104350@10.1.2.10;user=phone
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: sip:19375104350@10.1.2.10
Content-Length: 0

<------------>
[Jun 9 09:36:20] DEBUG[3327] devicestate.c: Notification of state change to be queued on device/channel SIP/243
[Jun 9 09:36:20] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - 243
[Jun 9 09:36:20] DEBUG[3301] chan_sip.c: Checking device state for peer 243
[Jun 9 09:36:20] DEBUG[3301] devicestate.c: Changing state for SIP/243 - state 1 (Not in use)
[Jun 9 09:36:20] DEBUG[3321] app_queue.c: Device ‘SIP/243’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:20] DEBUG[17044] pbx.c: Launching ‘Dial’
[Jun 9 09:36:20] VERBOSE[17044] logger.c: – Executing [19375104350@local:1] Dial(“SIP/243-0000002b”, “SIP/19375104350@gxw4108b”) in new stack
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Setting NAT on RTP to Off
[Jun 9 09:36:20] DEBUG[17044] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: *** Our native formats are 0x80004 (ulaw|h263)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: *** Joint capabilities are 0x0 (nothing)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263)
[Jun 9 09:36:20] DEBUG[17044] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: This channel will not be able to handle video.
[Jun 9 09:36:20] DEBUG[17044] rtp.c: Seeded SDP of ‘SIP/gxw4108b-0000002c’ with that of ‘SIP/243-0000002b’
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable DIALEDTIME.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable ANSWEREDTIME.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable DIALEDPEERNAME.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable DIALEDPEERNUMBER.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable DIALSTATUS.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable SIPCALLID.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable SIPUSERAGENT.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable SIPDOMAIN.
[Jun 9 09:36:20] DEBUG[17044] channel.c: Not copying variable SIPURI.
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Outgoing Call for 19375104350
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Updating call counter for outgoing call
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Our T38 capability (0), joint T38 capability (0)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: ** Our capability: 0x8000e (gsm|ulaw|alaw|h263) Video flag: False
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: ** Our prefcodec: 0x4 (ulaw)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: This call needs video offers, but there’s no video support enabled!
[Jun 9 09:36:20] VERBOSE[17044] logger.c: Audio is at 10.1.1.4 port 12516
[Jun 9 09:36:20] VERBOSE[17044] logger.c: Adding codec 0x4 (ulaw) to SDP
[Jun 9 09:36:20] VERBOSE[17044] logger.c: Adding codec 0x2 (gsm) to SDP
[Jun 9 09:36:20] VERBOSE[17044] logger.c: Adding codec 0x8 (alaw) to SDP
[Jun 9 09:36:20] VERBOSE[17044] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: – Done with adding codecs to SDP
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Done building SDP. Settling with this capability: 0x8000e (gsm|ulaw|alaw|h263)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 0: INVITE sip:19375104350@10.1.1.16 SIP/2.0 (40)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport (59)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16 (31)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 4: Contact: sip:243@10.1.1.4 (27)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 5: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 6: CSeq: 102 INVITE (16)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 8: Max-Forwards: 70 (16)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 9: Date: Mon, 09 Jun 2014 13:36:20 GMT (35)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO (72)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 11: Supported: replaces (19)
[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: Header 12: Content-Type: application/sdp (29)
[Jun 9 09:36:20] VERBOSE[17044] logger.c: Reliably Transmitting (no NAT) to 10.1.1.16:5060:
INVITE sip:19375104350@10.1.1.16 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16
Contact: sip:243@10.1.1.4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Mon, 09 Jun 2014 13:36:20 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 250

v=0
o=root 3297 3297 IN IP4 10.1.1.4
s=session
c=IN IP4 10.1.1.4
t=0 0
m=audio 12516 RTP/AVP 0 3 8 127
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=ptime:20
a=sendrecv

[Jun 9 09:36:20] DEBUG[17044] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:36:20] VERBOSE[17044] logger.c: – Called 19375104350@gxw4108b
[Jun 9 09:36:20] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 102 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4
Content-Length: 0

<------------->
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 100 Trying (18)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport (59)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16 (31)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4 (54)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 7: Content-Length: 0 (17)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: Header 8: (0)
[Jun 9 09:36:20] VERBOSE[3327] logger.c: — (8 headers 0 lines) —
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: = Found Their Call ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 Their Tag Our tag: as0304b2c0
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: *** SIP TIMER: Cancelling retransmission #5560 - INVITE (got response)
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ Request 102: Found
[Jun 9 09:36:20] DEBUG[3327] chan_sip.c: SIP response 100 to standard invite
[Jun 9 09:36:24] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 102 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4
Contact: sip:10.1.1.16:5060;transport=udp
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK
Content-Length: 0

<------------->
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport (59)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4 (52)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4 (54)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 7: Contact: sip:10.1.1.16:5060;transport=udp (43)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 9: Content-Length: 0 (17)
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: Header 10: (0)
[Jun 9 09:36:24] VERBOSE[3327] logger.c: — (10 headers 0 lines) —
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: = Found Their Call ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 Their Tag Our tag: as0304b2c0
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ Request 102: Found
[Jun 9 09:36:24] DEBUG[3327] chan_sip.c: SIP response 180 to standard invite
[Jun 9 09:36:24] DEBUG[3327] devicestate.c: Notification of state change to be queued on device/channel SIP/gxw4108b
[Jun 9 09:36:24] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - gxw4108b
[Jun 9 09:36:24] DEBUG[3301] chan_sip.c: Checking device state for peer gxw4108b
[Jun 9 09:36:24] DEBUG[3301] devicestate.c: Changing state for SIP/gxw4108b - state 1 (Not in use)
[Jun 9 09:36:24] VERBOSE[17044] logger.c: – SIP/gxw4108b-0000002c is ringing
[Jun 9 09:36:24] DEBUG[3321] app_queue.c: Device ‘SIP/gxw4108b’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:24] DEBUG[17044] rtp.c: Setting early bridge SDP of ‘SIP/243-0000002b’ with that of ‘SIP/gxw4108b-0000002c’
[Jun 9 09:36:24] VERBOSE[17044] logger.c:
<— Transmitting (no NAT) to 10.1.2.243:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK4279f84f9B3FBDF4;received=10.1.2.243
From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
To: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: sip:19375104350@10.1.2.10
Content-Length: 0

<------------>
[Jun 9 09:36:26] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 102 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4
Contact: sip:10.1.1.16:5060;transport=udp
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK
Content-Type: application/sdp
Supported: replaces, timer, 100rel, path
Content-Length: 218

v=0
o=system 8002 8000 IN IP4 10.1.1.16
s=SIP Call
c=IN IP4 10.1.1.16
t=0 0
m=audio 5012 RTP/AVP 0 8 4 18 3 2 127
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-11

<------------->
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport (59)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4 (52)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4 (54)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 7: Contact: sip:10.1.1.16:5060;transport=udp (43)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 9: Content-Type: application/sdp (29)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 10: Supported: replaces, timer, 100rel, path (40)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 11: Content-Length: 218 (19)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 12: (0)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: v=0 (3)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: o=system 8002 8000 IN IP4 10.1.1.16 (35)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: s=SIP Call (10)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: c=IN IP4 10.1.1.16 (18)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: t=0 0 (5)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: m=audio 5012 RTP/AVP 0 8 4 18 3 2 127 (37)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=sendrecv (10)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=ptime:20 (10)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=rtpmap:127 telephone-event/8000 (33)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=fmtp:127 0-11 (15)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: — (12 headers 11 lines) —
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: = Found Their Call ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 Their Tag b810c44573319fc4 Our tag: as0304b2c0
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Acked pending invite 102
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ of Request 102: Match Found
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: SIP response 200 to standard invite
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing session-level SDP o=system 8002 8000 IN IP4 10.1.1.16… UNSUPPORTED.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing session-level SDP s=SIP Call… UNSUPPORTED.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing session-level SDP c=IN IP4 10.1.1.16… OK.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 0
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 8
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 4
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 18
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 3
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 2
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found RTP audio format 127
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=sendrecv… OK.
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found audio description format PCMU for ID 0
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000… OK.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=ptime:20… OK.
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Found audio description format telephone-event for ID 127
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000… OK.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=fmtp:127 0-11… UNSUPPORTED.
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: T38 state changed to 0 on channel SIP/gxw4108b-0000002c
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x10f (g723|gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Our T38 capability = (0), peer T38 capability (0), joint T38 capability (0)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Peer audio RTP is at port 10.1.1.16:5012
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: We’re settling with these formats: 0xe (gsm|ulaw|alaw)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: We have an owner, now see if we need to change this call
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Updating call counter for outgoing call
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: build_route: Contact hop: sip:10.1.1.16:5060;transport=udp
[Jun 9 09:36:26] VERBOSE[3327] logger.c: list_route: hop: sip:10.1.1.16:5060;transport=udp
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Strict routing enforced for session 38858ed753a325960b02dd855f0d6354@10.1.1.4
[Jun 9 09:36:26] VERBOSE[3327] logger.c: set_destination: Parsing sip:10.1.1.16:5060;transport=udp for address/port to send to
[Jun 9 09:36:26] VERBOSE[3327] logger.c: set_destination: set destination to 10.1.1.16, port 5060
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Transmitting (no NAT) to 10.1.1.16:5060:
ACK sip:10.1.1.16:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK70399cc8;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Contact: sip:243@10.1.1.4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

[Jun 9 09:36:26] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 102 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4
Contact: sip:10.1.1.16:5060;transport=udp
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK
Content-Type: application/sdp
Supported: replaces, timer, 100rel, path
Content-Length: 218

v=0
o=system 8002 8001 IN IP4 10.1.1.16
s=SIP Call
c=IN IP4 10.1.1.16
t=0 0
m=audio 5012 RTP/AVP 0 8 4 18 3 2 127
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-11

<------------->
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK148c8cdc;rport (59)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4 (52)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4 (54)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 7: Contact: sip:10.1.1.16:5060;transport=udp (43)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 9: Content-Type: application/sdp (29)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 10: Supported: replaces, timer, 100rel, path (40)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 11: Content-Length: 218 (19)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 12: (0)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: v=0 (3)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: o=system 8002 8001 IN IP4 10.1.1.16 (35)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: s=SIP Call (10)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: c=IN IP4 10.1.1.16 (18)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: t=0 0 (5)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: m=audio 5012 RTP/AVP 0 8 4 18 3 2 127 (37)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=sendrecv (10)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=ptime:20 (10)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=rtpmap:127 telephone-event/8000 (33)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Line: a=fmtp:127 0-11 (15)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: — (12 headers 11 lines) —
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: = Found Their Call ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 Their Tag b810c44573319fc4 Our tag: as0304b2c0
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ of Request 102: Match Not Found
[Jun 9 09:36:26] DEBUG[17044] devicestate.c: Notification of state change to be queued on device/channel SIP/gxw4108b
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - gxw4108b
[Jun 9 09:36:26] VERBOSE[17044] logger.c: – SIP/gxw4108b-0000002c answered SIP/243-0000002b
[Jun 9 09:36:26] DEBUG[3301] chan_sip.c: Checking device state for peer gxw4108b
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Setting early bridge SDP of ‘SIP/243-0000002b’ with that of ‘SIP/gxw4108b-0000002c’
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: Changing state for SIP/gxw4108b - state 1 (Not in use)
[Jun 9 09:36:26] DEBUG[17044] devicestate.c: Notification of state change to be queued on device/channel SIP/243
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: SIP answering channel: SIP/243-0000002b
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Setting the marker bit due to a source update
[Jun 9 09:36:26] DEBUG[3321] app_queue.c: Device ‘SIP/gxw4108b’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - 243
[Jun 9 09:36:26] DEBUG[3301] chan_sip.c: Checking device state for peer 243
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: Changing state for SIP/243 - state 1 (Not in use)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Setting framing from config on incoming call
[Jun 9 09:36:26] DEBUG[3321] app_queue.c: Device ‘SIP/243’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Audio is at 10.1.2.10 port 19672
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Adding codec 0x4 (ulaw) to SDP
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Adding codec 0x8 (alaw) to SDP
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: – Done with adding codecs to SDP
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw)
[Jun 9 09:36:26] VERBOSE[17044] logger.c:
<— Reliably Transmitting (no NAT) to 10.1.2.243:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK4279f84f9B3FBDF4;received=10.1.2.243
From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
To: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: sip:19375104350@10.1.2.10
Content-Type: application/sdp
Content-Length: 229

v=0
o=root 3297 3297 IN IP4 10.1.2.10
s=session
c=IN IP4 10.1.2.10
t=0 0
m=audio 19672 RTP/AVP 0 8 127
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=ptime:20
a=sendrecv

<------------>
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:36:26] DEBUG[17044] res_features.c: Removing dialed interfaces datastore on SIP/gxw4108b-0000002c since we’re bridging
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Setting the marker bit due to a source update
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Setting the marker bit due to a source update
[Jun 9 09:36:26] VERBOSE[17044] logger.c: – Native bridging SIP/243-0000002b and SIP/gxw4108b-0000002c
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Deferring reinvite on SIP ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ - It’s audio will be redirected to IP 10.1.1.16
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Sending reinvite on SIP ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ - It’s audio soon redirected to IP 10.1.2.243
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Strict routing enforced for session 38858ed753a325960b02dd855f0d6354@10.1.1.4
[Jun 9 09:36:26] VERBOSE[17044] logger.c: set_destination: Parsing sip:10.1.1.16:5060;transport=udp for address/port to send to
[Jun 9 09:36:26] VERBOSE[17044] logger.c: set_destination: set destination to 10.1.1.16, port 5060
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: ** Our prefcodec: 0x4 (ulaw)
[Jun 9 09:36:26] NOTICE[17044] chan_sip.c: ** Our native-bridge filtered capablity: 0xc (ulaw|alaw)
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Audio is at 10.1.1.4 port 12516
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Adding codec 0x4 (ulaw) to SDP
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Adding codec 0x8 (alaw) to SDP
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: – Done with adding codecs to SDP
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Initializing already initialized SIP dialog 38858ed753a325960b02dd855f0d6354@10.1.1.4 (presumably reinvite)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 0: INVITE sip:10.1.1.16:5060;transport=udp SIP/2.0 (47)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK04787582;rport (59)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4 (52)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 4: Contact: sip:243@10.1.1.4 (27)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 5: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 6: CSeq: 103 INVITE (16)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 8: Max-Forwards: 70 (16)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO (72)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 10: Supported: replaces (19)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52)
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Header 12: Content-Type: application/sdp (29)
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Reliably Transmitting (no NAT) to 10.1.1.16:5060:
INVITE sip:10.1.1.16:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK04787582;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Contact: sip:243@10.1.1.4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 103 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
X-asterisk-Info: SIP re-invite (External RTP bridge)
Content-Type: application/sdp
Content-Length: 230

v=0
o=root 3297 3298 IN IP4 10.1.2.243
s=session
c=IN IP4 10.1.2.243
t=0 0
m=audio 2228 RTP/AVP 0 8 127
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=ptime:20
a=sendrecv

[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Oooh, ‘SIP/gxw4108b-0000002c’ changed end address to 10.1.1.16:5012 (format 12)
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Oooh, ‘SIP/gxw4108b-0000002c’ changed end vaddress to 0.0.0.0:0 (format 12)
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Oooh, ‘SIP/gxw4108b-0000002c’ was 10.1.1.16:5012/(format 14)
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Oooh, ‘SIP/gxw4108b-0000002c’ was 0.0.0.0:0/(format 14)
[Jun 9 09:36:26] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 484
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK04787582;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 103 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:8) 1.4.1.4
Content-Length: 0

<------------->
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 484 (12)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK04787582;rport (59)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (63)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4 (52)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 5: CSeq: 103 INVITE (16)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:8) 1.4.1.4 (54)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 7: Content-Length: 0 (17)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 8: (0)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: — (8 headers 0 lines) —
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: = Found Their Call ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 Their Tag b810c44573319fc4 Our tag: as0304b2c0
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Acked pending invite 103
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5564
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ of Request 103: Match Found
[Jun 9 09:36:26] VERBOSE[3327] logger.c: – Got SIP response 484 “” back from 10.1.1.16
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Strict routing enforced for session 38858ed753a325960b02dd855f0d6354@10.1.1.4
[Jun 9 09:36:26] VERBOSE[3327] logger.c: set_destination: Parsing sip:10.1.1.16:5060;transport=udp for address/port to send to
[Jun 9 09:36:26] VERBOSE[3327] logger.c: set_destination: set destination to 10.1.1.16, port 5060
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Transmitting (no NAT) to 10.1.1.16:5060:
ACK sip:10.1.1.16:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK04787582;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
To: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
Contact: sip:243@10.1.1.4
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 103 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Setting SIP_ALREADYGONE on dialog 38858ed753a325960b02dd855f0d6354@10.1.1.4
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Oooh, got a hangup
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Deferring reinvite on SIP ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ - It’s audio will be redirected to IP 10.1.2.10
[Jun 9 09:36:26] DEBUG[17044] channel.c: Returning from native bridge, channels: SIP/243-0000002b, SIP/gxw4108b-0000002c
[Jun 9 09:36:26] DEBUG[17044] channel.c: Hanging up channel ‘SIP/gxw4108b-0000002c’
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Hangup call SIP/gxw4108b-0000002c, SIP callid 38858ed753a325960b02dd855f0d6354@10.1.1.4)
[Jun 9 09:36:26] DEBUG[17044] devicestate.c: Notification of state change to be queued on device/channel SIP/gxw4108b
[Jun 9 09:36:26] DEBUG[17044] rtp.c: Channel ‘’ has no RTP, not doing anything
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - gxw4108b
[Jun 9 09:36:26] DEBUG[17044] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Jun 9 09:36:26] DEBUG[3301] chan_sip.c: Checking device state for peer gxw4108b
[Jun 9 09:36:26] DEBUG[17044] pbx.c: Spawn extension (local,19375104350,1) exited non-zero on ‘SIP/243-0000002b’
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: Changing state for SIP/gxw4108b - state 1 (Not in use)
[Jun 9 09:36:26] VERBOSE[17044] logger.c: == Spawn extension (local, 19375104350, 1) exited non-zero on ‘SIP/243-0000002b’
[Jun 9 09:36:26] DEBUG[17044] channel.c: Soft-Hanging up channel ‘SIP/243-0000002b’
[Jun 9 09:36:26] DEBUG[3321] app_queue.c: Device ‘SIP/gxw4108b’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:26] DEBUG[17044] channel.c: Hanging up channel ‘SIP/243-0000002b’
[Jun 9 09:36:26] DEBUG[17044] chan_sip.c: Hangup call SIP/243-0000002b, SIP callid 7491d971-f2ce8406-efb2ecf3@10.1.2.243)
[Jun 9 09:36:26] VERBOSE[17044] logger.c: Scheduling destruction of SIP dialog ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ in 32000 ms (Method: INVITE)
[Jun 9 09:36:26] DEBUG[17044] devicestate.c: Notification of state change to be queued on device/channel SIP/243
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - 243
[Jun 9 09:36:26] DEBUG[3301] chan_sip.c: Checking device state for peer 243
[Jun 9 09:36:26] DEBUG[3301] devicestate.c: Changing state for SIP/243 - state 1 (Not in use)
[Jun 9 09:36:26] DEBUG[3321] app_queue.c: Device ‘SIP/243’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:26] VERBOSE[3327] logger.c:
<— SIP read from 10.1.2.243:5060 —>
ACK sip:19375104350@10.1.2.10 SIP/2.0
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK21d8978C7EDE4D5
From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
To: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99
CSeq: 1 ACK
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
Contact: sip:243@10.1.2.243:5060
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267
Accept-Language: en
Max-Forwards: 70
Content-Length: 0

<------------->
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 0: ACK sip:19375104350@10.1.2.10 SIP/2.0 (37)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK21d8978C7EDE4D5 (62)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 2: From: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542 (52)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 3: To: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99 (57)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 4: CSeq: 1 ACK (11)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 5: Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243 (46)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 6: Contact: sip:243@10.1.2.243:5060 (34)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267 (54)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 9: Accept-Language: en (19)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 10: Max-Forwards: 70 (16)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 11: Content-Length: 0 (17)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 12: (0)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: — (12 headers 0 lines) —
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: = No match Their Call ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 Their Tag b810c44573319fc4 Our tag: as0304b2c0
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: = Found Their Call ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243 Their Tag AFF5F78D-A687542 Our tag: as12ad1f99
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5563
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ of Response 1: Match Found
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Strict routing enforced for session 7491d971-f2ce8406-efb2ecf3@10.1.2.243
[Jun 9 09:36:26] VERBOSE[3327] logger.c: set_destination: Parsing sip:243@10.1.2.243:5060 for address/port to send to
[Jun 9 09:36:26] VERBOSE[3327] logger.c: set_destination: set destination to 10.1.2.243, port 5060
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Reliably Transmitting (no NAT) to 10.1.2.243:5060:
BYE sip:243@10.1.2.243:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK357ba7a4;rport
From: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99
To: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
CSeq: 102 BYE
User-Agent: Asterisk PBX
Max-Forwards: 70
X-Asterisk-HangupCause: Invalid number format
X-Asterisk-HangupCauseCode: 28
Content-Length: 0

[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Scheduling destruction of SIP dialog ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ in 32000 ms (Method: ACK)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Really destroying SIP dialog ‘38858ed753a325960b02dd855f0d6354@10.1.1.4’ Method: INVITE
[Jun 9 09:36:26] VERBOSE[3327] logger.c:
<— SIP read from 10.1.2.243:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK357ba7a4;rport
From: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99
To: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542
CSeq: 102 BYE
Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243
Contact: sip:243@10.1.2.243:5060
User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267
Accept-Language: en
Content-Length: 0

<------------->
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.2.10:5060;branch=z9hG4bK357ba7a4;rport (60)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 2: From: sip:19375104350@10.1.2.10;user=phone;tag=as12ad1f99 (59)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 3: To: “243” sip:243@10.1.2.10;tag=AFF5F78D-A687542 (50)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 4: CSeq: 102 BYE (13)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 5: Call-ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243 (46)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 6: Contact: sip:243@10.1.2.243:5060 (34)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267 (54)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 8: Accept-Language: en (19)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 9: Content-Length: 0 (17)
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Header 10: (0)
[Jun 9 09:36:26] VERBOSE[3327] logger.c: — (10 headers 0 lines) —
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: = Found Their Call ID: 7491d971-f2ce8406-efb2ecf3@10.1.2.243 Their Tag AFF5F78D-A687542 Our tag: as12ad1f99
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5566
[Jun 9 09:36:26] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ of Request 102: Match Found
[Jun 9 09:36:26] VERBOSE[3327] logger.c: SIP Response message for INCOMING dialog BYE arrived
[Jun 9 09:36:26] VERBOSE[3327] logger.c: Really destroying SIP dialog ‘7491d971-f2ce8406-efb2ecf3@10.1.2.243’ Method: ACK
[Jun 9 09:36:48] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
BYE sip:243@10.1.1.4 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.16:5060;branch=z9hG4bK16f51010c076f950
From: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
To: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 2105 BYE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK
Reason: SIP ;text="FX call terminated"
Content-Length: 0[/quote]

gwurst · June 9, 2014, 1:39pm

[quote]<------------->
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 0: BYE sip:243@10.1.1.4 SIP/2.0 (28)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.16:5060;branch=z9hG4bK16f51010c076f950 (62)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 2: From: sip:19375104350@10.1.1.16;tag=b810c44573319fc4 (54)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 3: To: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0 (61)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4 (50)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 5: CSeq: 2105 BYE (14)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:2) 1.4.1.4 (54)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 7: Max-Forwards: 70 (16)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 9: Reason: SIP ;text=“FX call terminated” (38)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 10: Content-Length: 0 (17)
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Header 11: (0)
[Jun 9 09:36:48] VERBOSE[3327] logger.c: — (11 headers 0 lines) —
[Jun 9 09:36:48] VERBOSE[3327] logger.c: Sending to 10.1.1.16 : 5060 (no NAT)
[Jun 9 09:36:48] VERBOSE[3327] logger.c:
<— Transmitting (no NAT) to 10.1.1.16:5060 —>
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/UDP 10.1.1.16:5060;branch=z9hG4bK16f51010c076f950;received=10.1.1.16
From: sip:19375104350@10.1.1.16;tag=b810c44573319fc4
To: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as0304b2c0
Call-ID: 38858ed753a325960b02dd855f0d6354@10.1.1.4
CSeq: 2105 BYE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------>
[Jun 9 09:36:48] DEBUG[3327] chan_sip.c: Invalid SIP message - rejected , no callid, len 495
[Jun 9 09:36:59] VERBOSE[3327] logger.c:
<— SIP read from 10.1.2.243:5060 —>
INVITE sip:8003523407@10.1.2.10:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D
From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB
To: sip:8003523407@10.1.2.10;user=phone
CSeq: 1 INVITE
Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243
Contact: sip:243@10.1.2.243:5060
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267
Accept-Language: en
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 290

v=0
o=- 1168010855 1168010855 IN IP4 10.1.2.243
s=Polycom IP Phone
c=IN IP4 10.1.2.243
t=0 0
a=sendrecv
m=audio 2232 RTP/AVP 9 0 8 18 127
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:127 telephone-event/8000

<------------->
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 0: INVITE sip:8003523407@10.1.2.10:5060;user=phone SIP/2.0 (55)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D (63)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 2: From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB (53)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 3: To: sip:8003523407@10.1.2.10;user=phone (41)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 4: CSeq: 1 INVITE (14)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 5: Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243 (46)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 6: Contact: sip:243@10.1.2.243:5060 (34)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267 (54)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 9: Accept-Language: en (19)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 10: Supported: 100rel,replaces (26)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 11: Allow-Events: talk,hold,conference (34)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 12: Max-Forwards: 70 (16)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 13: Content-Type: application/sdp (29)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 14: Content-Length: 290 (19)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 15: (0)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: v=0 (3)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: o=- 1168010855 1168010855 IN IP4 10.1.2.243 (43)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: s=Polycom IP Phone (18)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: c=IN IP4 10.1.2.243 (19)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: t=0 0 (5)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=sendrecv (10)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: m=audio 2232 RTP/AVP 9 0 8 18 127 (33)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=rtpmap:9 G722/8000 (20)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=fmtp:18 annexb=no (19)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Line: a=rtpmap:127 telephone-event/8000 (33)
[Jun 9 09:36:59] VERBOSE[3327] logger.c: — (15 headers 13 lines) —
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Setting NAT on RTP to Off
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Allocating new SIP dialog for f7e92152-e619b3df-41f28d04@10.1.2.243 - INVITE (With RTP)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Begin: parsing SIP “Supported: 100rel,replaces”
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Found SIP option: -100rel-
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Matched SIP option: 100rel
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Found SIP option: -replaces-
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Matched SIP option: replaces
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Sending to 10.1.2.243 : 5060 (no NAT)
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Using INVITE request as basis request - f7e92152-e619b3df-41f28d04@10.1.2.243
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Setting NAT on RTP to Off
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found user ‘243’
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing session-level SDP o=- 1168010855 1168010855 IN IP4 10.1.2.243… UNSUPPORTED.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing session-level SDP s=Polycom IP Phone… UNSUPPORTED.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing session-level SDP c=IN IP4 10.1.2.243… OK.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing session-level SDP a=sendrecv… OK.
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found RTP audio format 9
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found RTP audio format 0
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found RTP audio format 8
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found RTP audio format 18
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found RTP audio format 127
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found audio description format G722 for ID 9
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000… OK.
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found audio description format PCMU for ID 0
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000… OK.
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found audio description format PCMA for ID 8
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000… OK.
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found audio description format G729 for ID 18
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000… OK.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no… UNSUPPORTED.
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Found audio description format telephone-event for ID 127
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000… OK.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: T38 state changed to 0 on channel
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x110c (ulaw|alaw|g729|g722)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Our T38 capability = (0), peer T38 capability (0), joint T38 capability (0)
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Peer audio RTP is at port 10.1.2.243:2232
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: We’re settling with these formats: 0xc (ulaw|alaw)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Checking SIP call limits for device 243
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Updating call counter for incoming call
[Jun 9 09:36:59] VERBOSE[3327] logger.c: Looking for 8003523407 in local (domain 10.1.2.10)
[Jun 9 09:36:59] DEBUG[3327] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: *** Our native formats are 0x4 (ulaw)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263)
[Jun 9 09:36:59] DEBUG[3327] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: This channel will not be able to handle video.
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: build_route: Contact hop: sip:243@10.1.2.243:5060
[Jun 9 09:36:59] VERBOSE[3327] logger.c: list_route: hop: sip:243@10.1.2.243:5060
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: SIP/243-0000002d: New call is still down… Trying…
[Jun 9 09:36:59] VERBOSE[3327] logger.c:
<— Transmitting (no NAT) to 10.1.2.243:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D;received=10.1.2.243
From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB
To: sip:8003523407@10.1.2.10;user=phone
Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: sip:8003523407@10.1.2.10
Content-Length: 0

<------------>
[Jun 9 09:36:59] DEBUG[3327] devicestate.c: Notification of state change to be queued on device/channel SIP/243
[Jun 9 09:36:59] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - 243
[Jun 9 09:36:59] DEBUG[3301] chan_sip.c: Checking device state for peer 243
[Jun 9 09:36:59] DEBUG[3301] devicestate.c: Changing state for SIP/243 - state 1 (Not in use)
[Jun 9 09:36:59] DEBUG[3321] app_queue.c: Device ‘SIP/243’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:36:59] DEBUG[17045] pbx.c: Launching ‘Dial’
[Jun 9 09:36:59] VERBOSE[17045] logger.c: – Executing [8003523407@local:1] Dial(“SIP/243-0000002d”, “SIP/8003523407@gxw4108b”) in new stack
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Setting NAT on RTP to Off
[Jun 9 09:36:59] DEBUG[17045] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: *** Our native formats are 0x80004 (ulaw|h263)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: *** Joint capabilities are 0x0 (nothing)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263)
[Jun 9 09:36:59] DEBUG[17045] frame.c: Could not find preferred codec - Going for the best codec
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: This channel will not be able to handle video.
[Jun 9 09:36:59] DEBUG[17045] rtp.c: Seeded SDP of ‘SIP/gxw4108b-0000002e’ with that of ‘SIP/243-0000002d’
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable DIALEDTIME.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable ANSWEREDTIME.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable DIALEDPEERNAME.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable DIALEDPEERNUMBER.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable DIALSTATUS.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable SIPCALLID.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable SIPUSERAGENT.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable SIPDOMAIN.
[Jun 9 09:36:59] DEBUG[17045] channel.c: Not copying variable SIPURI.
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Outgoing Call for 8003523407
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Updating call counter for outgoing call
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Our T38 capability (0), joint T38 capability (0)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: ** Our capability: 0x8000e (gsm|ulaw|alaw|h263) Video flag: False
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: ** Our prefcodec: 0x4 (ulaw)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: This call needs video offers, but there’s no video support enabled!
[Jun 9 09:36:59] VERBOSE[17045] logger.c: Audio is at 10.1.1.4 port 19736
[Jun 9 09:36:59] VERBOSE[17045] logger.c: Adding codec 0x4 (ulaw) to SDP
[Jun 9 09:36:59] VERBOSE[17045] logger.c: Adding codec 0x2 (gsm) to SDP
[Jun 9 09:36:59] VERBOSE[17045] logger.c: Adding codec 0x8 (alaw) to SDP
[Jun 9 09:36:59] VERBOSE[17045] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: – Done with adding codecs to SDP
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Done building SDP. Settling with this capability: 0x8000e (gsm|ulaw|alaw|h263)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 0: INVITE sip:8003523407@10.1.1.16 SIP/2.0 (39)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport (59)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c (63)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 3: To: sip:8003523407@10.1.1.16 (30)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 4: Contact: sip:243@10.1.1.4 (27)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 5: Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 (50)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 6: CSeq: 102 INVITE (16)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 8: Max-Forwards: 70 (16)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 9: Date: Mon, 09 Jun 2014 13:36:59 GMT (35)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO (72)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 11: Supported: replaces (19)
[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: Header 12: Content-Type: application/sdp (29)
[Jun 9 09:36:59] VERBOSE[17045] logger.c: Reliably Transmitting (no NAT) to 10.1.1.16:5060:
INVITE sip:8003523407@10.1.1.16 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c
To: sip:8003523407@10.1.1.16
Contact: sip:243@10.1.1.4
Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Mon, 09 Jun 2014 13:36:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 250

v=0
o=root 3297 3297 IN IP4 10.1.1.4
s=session
c=IN IP4 10.1.1.4
t=0 0
m=audio 19736 RTP/AVP 0 3 8 127
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:127 telephone-event/8000
a=fmtp:127 0-16
a=ptime:20
a=sendrecv

[Jun 9 09:36:59] DEBUG[17045] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:36:59] VERBOSE[17045] logger.c: – Called 8003523407@gxw4108b
[Jun 9 09:36:59] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c
To: sip:8003523407@10.1.1.16
Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4
CSeq: 102 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:3) 1.4.1.4
Content-Length: 0

<------------->
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 100 Trying (18)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport (59)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c (63)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 3: To: sip:8003523407@10.1.1.16 (30)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 (50)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:3) 1.4.1.4 (54)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 7: Content-Length: 0 (17)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: Header 8: (0)
[Jun 9 09:36:59] VERBOSE[3327] logger.c: — (8 headers 0 lines) —
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: = Found Their Call ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 Their Tag Our tag: as776fc66c
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: *** SIP TIMER: Cancelling retransmission #5569 - INVITE (got response)
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ Request 102: Found
[Jun 9 09:36:59] DEBUG[3327] chan_sip.c: SIP response 100 to standard invite
[Jun 9 09:37:00] VERBOSE[3327] logger.c:
<— SIP read from 10.1.2.243:5060 —>
CANCEL sip:8003523407@10.1.2.10:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D
From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB
To: sip:8003523407@10.1.2.10;user=phone
CSeq: 1 CANCEL
Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243
Contact: sip:243@10.1.2.243:5060
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267
Max-Forwards: 70
Content-Length: 0

<------------->
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 0: CANCEL sip:8003523407@10.1.2.10:5060;user=phone SIP/2.0 (55)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D (63)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 2: From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB (53)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 3: To: sip:8003523407@10.1.2.10;user=phone (41)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 4: CSeq: 1 CANCEL (14)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 5: Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243 (46)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 6: Contact: sip:243@10.1.2.243:5060 (34)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267 (54)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 9: Max-Forwards: 70 (16)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 10: Content-Length: 0 (17)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 11: (0)
[Jun 9 09:37:00] VERBOSE[3327] logger.c: — (11 headers 0 lines) —
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: = No match Their Call ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 Their Tag Our tag: as776fc66c
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: = Found Their Call ID: f7e92152-e619b3df-41f28d04@10.1.2.243 Their Tag D4D54A0E-CFA5BABB Our tag: as162b144d
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL
[Jun 9 09:37:00] VERBOSE[3327] logger.c: Sending to 10.1.2.243 : 5060 (no NAT)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Setting SIP_ALREADYGONE on dialog f7e92152-e619b3df-41f28d04@10.1.2.243
[Jun 9 09:37:00] VERBOSE[3327] logger.c:
<— Reliably Transmitting (no NAT) to 10.1.2.243:5060 —>
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D;received=10.1.2.243
From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB
To: sip:8003523407@10.1.2.10;user=phone;tag=as162b144d
Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------>
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:37:00] VERBOSE[3327] logger.c:
<— Transmitting (no NAT) to 10.1.2.243:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D;received=10.1.2.243
From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB
To: sip:8003523407@10.1.2.10;user=phone;tag=as162b144d
Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243
CSeq: 1 CANCEL
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------>
[Jun 9 09:37:00] DEBUG[17045] rtp.c: Channel ‘’ has no RTP, not doing anything
[Jun 9 09:37:00] DEBUG[17045] channel.c: Hanging up channel ‘SIP/gxw4108b-0000002e’
[Jun 9 09:37:00] DEBUG[17045] chan_sip.c: Hangup call SIP/gxw4108b-0000002e, SIP callid 6398f0ef41da057f03960bfd40040d58@10.1.1.4)
[Jun 9 09:37:00] DEBUG[17045] chan_sip.c: Hanging up channel in state Down (not UP)
[Jun 9 09:37:00] VERBOSE[17045] logger.c: Scheduling destruction of SIP dialog ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ in 32000 ms (Method: INVITE)
[Jun 9 09:37:00] DEBUG[17045] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ Request 102: Found
[Jun 9 09:37:00] VERBOSE[17045] logger.c: Reliably Transmitting (no NAT) to 10.1.1.16:5060:
CANCEL sip:8003523407@10.1.1.16 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c
To: sip:8003523407@10.1.1.16
Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4
CSeq: 102 CANCEL
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

[Jun 9 09:37:00] DEBUG[17045] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1
[Jun 9 09:37:00] VERBOSE[17045] logger.c: Scheduling destruction of SIP dialog ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ in 32000 ms (Method: INVITE)
[Jun 9 09:37:00] DEBUG[17045] devicestate.c: Notification of state change to be queued on device/channel SIP/gxw4108b
[Jun 9 09:37:00] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - gxw4108b
[Jun 9 09:37:00] DEBUG[3301] chan_sip.c: Checking device state for peer gxw4108b
[Jun 9 09:37:00] DEBUG[3301] devicestate.c: Changing state for SIP/gxw4108b - state 1 (Not in use)
[Jun 9 09:37:00] DEBUG[17045] app_dial.c: Exiting with DIALSTATUS=CANCEL.
[Jun 9 09:37:00] DEBUG[3321] app_queue.c: Device ‘SIP/gxw4108b’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:37:00] DEBUG[17045] pbx.c: Spawn extension (local,8003523407,1) exited non-zero on ‘SIP/243-0000002d’
[Jun 9 09:37:00] VERBOSE[17045] logger.c: == Spawn extension (local, 8003523407, 1) exited non-zero on ‘SIP/243-0000002d’
[Jun 9 09:37:00] DEBUG[17045] channel.c: Soft-Hanging up channel ‘SIP/243-0000002d’
[Jun 9 09:37:00] DEBUG[17045] channel.c: Hanging up channel ‘SIP/243-0000002d’
[Jun 9 09:37:00] DEBUG[17045] chan_sip.c: Hangup call SIP/243-0000002d, SIP callid f7e92152-e619b3df-41f28d04@10.1.2.243)
[Jun 9 09:37:00] DEBUG[17045] chan_sip.c: Hanging up channel in state Ring (not UP)
[Jun 9 09:37:00] DEBUG[17045] devicestate.c: Notification of state change to be queued on device/channel SIP/243
[Jun 9 09:37:00] DEBUG[3301] devicestate.c: No provider found, checking channel drivers for SIP - 243
[Jun 9 09:37:00] DEBUG[3301] chan_sip.c: Checking device state for peer 243
[Jun 9 09:37:00] DEBUG[3301] devicestate.c: Changing state for SIP/243 - state 1 (Not in use)
[Jun 9 09:37:00] DEBUG[3321] app_queue.c: Device ‘SIP/243’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jun 9 09:37:00] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c
To: sip:8003523407@10.1.1.16;tag=42138d9311f26f02
Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4
CSeq: 102 CANCEL
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:3) 1.4.1.4
Supported: replaces, timer, 100rel, path
Content-Length: 0

<------------->
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport (59)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c (63)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 3: To: sip:8003523407@10.1.1.16;tag=42138d9311f26f02 (51)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 (50)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 CANCEL (16)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:3) 1.4.1.4 (54)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 7: Supported: replaces, timer, 100rel, path (40)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 8: Content-Length: 0 (17)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 9: (0)
[Jun 9 09:37:00] VERBOSE[3327] logger.c: — (9 headers 0 lines) —
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: = Found Their Call ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 Their Tag Our tag: as776fc66c
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Acked pending invite 102
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5573
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ of Request 102: Match Found
[Jun 9 09:37:00] VERBOSE[3327] logger.c:
<— SIP read from 10.1.1.16:5060 —>
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c
To: sip:8003523407@10.1.1.16;tag=b6877165aaa59595
Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4
CSeq: 102 INVITE
User-Agent: Grandstream GXW4108 (HW 2.2, Ch:3) 1.4.1.4
Content-Length: 0

<------------->
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 0: SIP/2.0 487 Request Cancelled (29)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport (59)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 2: From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c (63)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 3: To: sip:8003523407@10.1.1.16;tag=b6877165aaa59595 (51)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 4: Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 (50)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 6: User-Agent: Grandstream GXW4108 (HW 2.2, Ch:3) 1.4.1.4 (54)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 7: Content-Length: 0 (17)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 8: (0)
[Jun 9 09:37:00] VERBOSE[3327] logger.c: — (8 headers 0 lines) —
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: = Found Their Call ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 Their Tag 42138d9311f26f02 Our tag: as776fc66c
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ of Request 102: Match Found
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: SIP response 487 to standard invite
[Jun 9 09:37:00] VERBOSE[3327] logger.c: Transmitting (no NAT) to 10.1.1.16:5060:
ACK sip:8003523407@10.1.1.16 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.4:5060;branch=z9hG4bK026bd4d2;rport
From: “Stephanie Young-Helou” sip:243@10.1.1.4;tag=as776fc66c
To: sip:8003523407@10.1.1.16;tag=b6877165aaa59595
Contact: sip:243@10.1.1.4
Call-ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0

[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Updating call counter for outgoing call
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Setting SIP_ALREADYGONE on dialog 6398f0ef41da057f03960bfd40040d58@10.1.1.4
[Jun 9 09:37:00] VERBOSE[3327] logger.c:
<— SIP read from 10.1.2.243:5060 —>
ACK sip:8003523407@10.1.2.10:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D
From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB
To: sip:8003523407@10.1.2.10;user=phone;tag=as162b144d
CSeq: 1 ACK
Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243
Contact: sip:243@10.1.2.243:5060
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267
Accept-Language: en
Max-Forwards: 70
Content-Length: 0

<------------->
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 0: ACK sip:8003523407@10.1.2.10:5060;user=phone SIP/2.0 (52)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.2.243:5060;branch=z9hG4bK771261007858B81D (63)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 2: From: “243” sip:243@10.1.2.10;tag=D4D54A0E-CFA5BABB (53)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 3: To: sip:8003523407@10.1.2.10;user=phone;tag=as162b144d (56)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 4: CSeq: 1 ACK (11)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 5: Call-ID: f7e92152-e619b3df-41f28d04@10.1.2.243 (46)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 6: Contact: sip:243@10.1.2.243:5060 (34)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_335-UA/3.2.4.0267 (54)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 9: Accept-Language: en (19)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 10: Max-Forwards: 70 (16)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 11: Content-Length: 0 (17)
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Header 12: (0)
[Jun 9 09:37:00] VERBOSE[3327] logger.c: — (12 headers 0 lines) —
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: = No match Their Call ID: 6398f0ef41da057f03960bfd40040d58@10.1.1.4 Their Tag b6877165aaa59595 Our tag: as776fc66c
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: = Found Their Call ID: f7e92152-e619b3df-41f28d04@10.1.2.243 Their Tag D4D54A0E-CFA5BABB Our tag: as162b144d
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5571
[Jun 9 09:37:00] DEBUG[3327] chan_sip.c: Stopping retransmission on ‘f7e92152-e619b3df-41f28d04@10.1.2.243’ of Response 1: Match Found
[Jun 9 09:37:00] VERBOSE[3327] logger.c: Really destroying SIP dialog ‘6398f0ef41da057f03960bfd40040d58@10.1.1.4’ Method: INVITE
[Jun 9 09:37:00] VERBOSE[3327] logger.c: Really destroying SIP dialog ‘f7e92152-e619b3df-41f28d04@10.1.2.243’ Method: ACK[/quote]

Thanks for the help!

david55 · June 9, 2014, 2:37pm

Please edit your postings to put code or quote blocks around the logs.

The first call is fully answered, not abandoned during ringing.

There is a bug in the Grandstream; it is sending a contact header with no user part then objecting to the lack of a user part in a subsequent re-invite. To work round, disable all re-invites (session timers, directmedia, and connected line update (sendrpid).

gwurst · June 9, 2014, 3:03pm

Thank you!!

I added the following to the SIP.CONF and they can place calls now:

[quote]
sendrpid = no
canreinvite = no
session-timers = refuse[/quote]

You really saved our bacon here. I have another question about getting all three Grandstream boxes used for outgoing calls, but that is a separate concern so I’ll start another thread.

Thanks again,

Greg

Topic		Replies	Views
Inbound SIP, phones don't ring Asterisk Support	12	821	August 24, 2012
Problem with outgoing call Asterisk Support	6	333	March 31, 2010
Outgoing call cut at the same moment that redirect Asterisk Support	5	214	November 5, 2015
Losing incoming calls Asterisk Support	2	362	August 11, 2014
Call disconnects immediately Asterisk Support	25	4125	October 14, 2013

Outgoing calls phone disconnects about the first ringback

Related topics