Jun 21 14:33:09 VERBOSE[17109] logger.c: Asterisk Event Logger restarted Jun 21 14:33:09 VERBOSE[17109] logger.c: Asterisk Queue Logger restarted Jun 21 14:33:19 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.124:5060: INVITE sip:3097@pfdesenv.planetarium.com.br SIP/2.0 Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKBX8ywpFztWuCEgmZ Max-Forwards: 70 User-Agent: SOYO.SIP V1.49.002 CFG0 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 Contact: CSeq: 1 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 235 v=0 o=- 12991292 60163890 IN IP4 172.16.10.124 s=SIP CALL c=IN IP4 172.16.10.124 t=0 0 m=audio 1722 RTP/AVP 18 4 0 8 3 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 0: INVITE sip:3097@pfdesenv.planetarium.com.br SIP/2.0 (51) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKBX8ywpFztWuCEgmZ (66) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 2: Max-Forwards: 70 (16) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 3: User-Agent: SOYO.SIP V1.49.002 CFG0 (36) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 4: From: "3050" ;tag=suzM66WNr09urc4w (72) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 5: To: "3097" (49) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 6: Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 (39) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 7: Contact: (38) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 8: CSeq: 1 INVITE (14) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 9: Supported: replaces (19) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 10: Content-Type: application/sdp (29) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 11: Content-Length: 235 (19) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 12: (0) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: o=- 12991292 60163890 IN IP4 172.16.10.124 (42) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: s=SIP CALL (10) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: c=IN IP4 172.16.10.124 (22) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 4 0 8 3 (31) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 21 14:33:19 VERBOSE[17112] logger.c: --- (12 headers 11 lines)Jun 21 14:33:19 VERBOSE[17112] logger.c: --- (12 headers 11 lines)--- Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Allocating new SIP dialog for XwwleZrXLRTRbZSJ@172.16.10.124 - INVITE (With RTP) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Begin: parsing SIP "Supported: replaces" Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Found SIP option: -replaces- Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Matched SIP option: replaces Jun 21 14:33:19 DEBUG[17112] chan_sip.c: * SIP extension value: 1 for call XwwleZrXLRTRbZSJ@172.16.10.124 Jun 21 14:33:19 VERBOSE[17112] logger.c: Using INVITE request as basis request - XwwleZrXLRTRbZSJ@172.16.10.124 Jun 21 14:33:19 VERBOSE[17112] logger.c: Sending to 172.16.10.124 : 5060 (non-NAT) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Setting NAT on RTP to 524288 Jun 21 14:33:19 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.124:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKBX8ywpFztWuCEgmZ;received=172.16.10.124 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" ;tag=as5586d481 Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="289acd1a" Content-Length: 0 --- Jun 21 14:33:19 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #23 Jun 21 14:33:19 VERBOSE[17112] logger.c: Scheduling destruction of call 'XwwleZrXLRTRbZSJ@172.16.10.124' in 15000 ms Jun 21 14:33:19 VERBOSE[17112] logger.c: Found user '3050' Jun 21 14:33:19 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.124:5060: ACK sip:3097@pfdesenv.planetarium.com.br SIP/2.0 Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKBX8ywpFztWuCEgmZ Max-Forwards: 70 User-Agent: SOYO.SIP V1.49.002 CFG0 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" ;tag=as5586d481 Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 Contact: CSeq: 1 ACK Content-Length: 0 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 0: ACK sip:3097@pfdesenv.planetarium.com.br SIP/2.0 (48) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKBX8ywpFztWuCEgmZ (66) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 2: Max-Forwards: 70 (16) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 3: User-Agent: SOYO.SIP V1.49.002 CFG0 (36) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 4: From: "3050" ;tag=suzM66WNr09urc4w (72) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 5: To: "3097" ;tag=as5586d481 (64) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 6: Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 (39) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 7: Contact: (38) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 8: CSeq: 1 ACK (11) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 9: Content-Length: 0 (17) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 10: (0) Jun 21 14:33:19 VERBOSE[17112] logger.c: --- (10 headers 0 lines)Jun 21 14:33:19 VERBOSE[17112] logger.c: --- (10 headers 0 lines)--- Jun 21 14:33:19 DEBUG[17112] chan_sip.c: = Found Their Call ID: XwwleZrXLRTRbZSJ@172.16.10.124 Their Tag suzM66WNr09urc4w Our tag: as5586d481 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 14:33:19 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #23 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Stopping retransmission on 'XwwleZrXLRTRbZSJ@172.16.10.124' of Response 1: Match Found Jun 21 14:33:19 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.124:5060: INVITE sip:3097@pfdesenv.planetarium.com.br SIP/2.0 Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKhAmiFQJ1YPzGUAuS Max-Forwards: 70 User-Agent: SOYO.SIP V1.49.002 CFG0 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 Contact: Proxy-Authorization: Digest username="3050", realm="asterisk", nonce="289acd1a", uri="sip:3097@pfdesenv.planetarium.com.br", response="6dd9da7854f9eb8212cd55da20d512b5", algorithm=MD5 CSeq: 2 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 235 v=0 o=- 71655316 67981128 IN IP4 172.16.10.124 s=SIP CALL c=IN IP4 172.16.10.124 t=0 0 m=audio 1722 RTP/AVP 18 4 0 8 3 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 0: INVITE sip:3097@pfdesenv.planetarium.com.br SIP/2.0 (51) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKhAmiFQJ1YPzGUAuS (66) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 2: Max-Forwards: 70 (16) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 3: User-Agent: SOYO.SIP V1.49.002 CFG0 (36) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 4: From: "3050" ;tag=suzM66WNr09urc4w (72) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 5: To: "3097" (49) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 6: Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 (39) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 7: Contact: (38) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 8: Proxy-Authorization: Digest username="3050", realm="asterisk", nonce="289acd1a", uri="sip:3097@pfdesenv.planetarium.com.br", response="6dd9da7854f9eb8212cd55da20d512b5", algorithm=MD5 (183) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 9: CSeq: 2 INVITE (14) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 10: Supported: replaces (19) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 12: Content-Length: 235 (19) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Header 13: (0) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: o=- 71655316 67981128 IN IP4 172.16.10.124 (42) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: s=SIP CALL (10) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: c=IN IP4 172.16.10.124 (22) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: m=audio 1722 RTP/AVP 18 4 0 8 3 (31) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 21 14:33:19 VERBOSE[17112] logger.c: --- (13 headers 11 lines)Jun 21 14:33:19 VERBOSE[17112] logger.c: --- (13 headers 11 lines)--- Jun 21 14:33:19 DEBUG[17112] chan_sip.c: = Found Their Call ID: XwwleZrXLRTRbZSJ@172.16.10.124 Their Tag suzM66WNr09urc4w Our tag: as5586d481 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 14:33:19 VERBOSE[17112] logger.c: Using INVITE request as basis request - XwwleZrXLRTRbZSJ@172.16.10.124 Jun 21 14:33:19 VERBOSE[17112] logger.c: Sending to 172.16.10.124 : 5060 (NAT) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Setting NAT on RTP to 524288 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found user '3050' Jun 21 14:33:19 VERBOSE[17112] logger.c: Found RTP audio format 18 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found RTP audio format 4 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found RTP audio format 0 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found RTP audio format 8 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found RTP audio format 3 Jun 21 14:33:19 VERBOSE[17112] logger.c: Peer audio RTP is at port 172.16.10.124:1722 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Peer audio RTP is at port 172.16.10.124:1722 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found description format G729 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found description format G723 Jun 21 14:33:19 VERBOSE[17112] logger.c: Found description format PCMU Jun 21 14:33:19 VERBOSE[17112] logger.c: Found description format PCMA Jun 21 14:33:19 VERBOSE[17112] logger.c: Found description format GSM Jun 21 14:33:19 VERBOSE[17112] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0x10f (g723|gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x8 (alaw) Jun 21 14:33:19 VERBOSE[17112] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Checking SIP call limits for device 3050 Jun 21 14:33:19 DEBUG[17112] chan_sip.c: Updating call counter for incoming call Jun 21 14:33:19 VERBOSE[17112] logger.c: Looking for 3097 in 3050_aux (domain pfdesenv.planetarium.com.br) Jun 21 14:33:19 DEBUG[17112] chan_sip.c: build_route: Contact hop: Jun 21 14:33:19 VERBOSE[17112] logger.c: list_route: hop: Jun 21 14:33:19 VERBOSE[17112] logger.c: Transmitting (NAT) to 172.16.10.124:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKhAmiFQJ1YPzGUAuS;received=172.16.10.124 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 14:33:19 DEBUG[17095] chan_sip.c: Checking device state for peer 3050 Jun 21 14:33:19 DEBUG[17095] devicestate.c: Changing state for SIP/3050 - state 2 (In use) Jun 21 14:33:19 DEBUG[17128] pbx.c: Expression result is '0' Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'GotoIf' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing GotoIf("SIP/3050-e3c1", "0 ? 1000") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Not taking any branch Jun 21 14:33:19 DEBUG[17128] pbx.c: Expression result is '1' Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'GotoIf' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing GotoIf("SIP/3050-e3c1", "1 ? 200:400") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_aux,3097,200) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'DBget' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing DBget("SIP/3050-e3c1", "ramalbloqueado=BLOQUEIORAMAL/3050") in new stack Jun 21 14:33:19 WARNING[17128] app_db.c: This application has been deprecated, please use the ${DB(family/key)} function instead. Jun 21 14:33:19 VERBOSE[17128] logger.c: -- DBget: varname=ramalbloqueado, family=BLOQUEIORAMAL, key=3050 Jun 21 14:33:19 DEBUG[17128] db.c: Unable to find key '3050' in family 'BLOQUEIORAMAL' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- DBget: Value not found in database. Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "400") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_aux,3097,400) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "NUMERODISCADO=3097") in new stack Jun 21 14:33:19 WARNING[17128] pbx.c: SetVar is deprecated, please use Set instead. Jun 21 14:33:19 DEBUG[17128] pbx.c: Expression result is '0' Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'GotoIf' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing GotoIf("SIP/3050-e3c1", "0 ? 404") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Not taking any branch Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "TRANSFER_CONTEXT=3050_aux") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Set' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Set("SIP/3050-e3c1", "GROUP=3050") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "LIMIT_WARNING_FILE=beep") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "LIMIT_TIMEOUT_FILE=beep5") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "500") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_aux,3097,500) Jun 21 14:33:19 DEBUG[17128] pbx.c: Expression result is '0' Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'GotoIf' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing GotoIf("SIP/3050-e3c1", "0 ? 700") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Not taking any branch Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'DBget' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing DBget("SIP/3050-e3c1", "GRAVACAOCHAMADASAIDA=GRAVACAOCHAMADASAIDA/3050") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- DBget: varname=GRAVACAOCHAMADASAIDA, family=GRAVACAOCHAMADASAIDA, key=3050 Jun 21 14:33:19 DEBUG[17128] db.c: Unable to find key '3050' in family 'GRAVACAOCHAMADASAIDA' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- DBget: Value not found in database. Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "700") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_aux,3097,700) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "3050_out|3097|1") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_out,3097,1) Jun 21 14:33:19 DEBUG[17128] pbx.c: Expression result is '1' Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'GotoIf' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing GotoIf("SIP/3050-e3c1", "1 ? 2:5") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_out,3097,2) Jun 21 14:33:19 DEBUG[17128] pbx.c: Expression result is '1' Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'GotoIf' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing GotoIf("SIP/3050-e3c1", "1 ? 3:5") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (3050_out,3097,3) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "CHAMADAINTERNA=T") in new stack Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetCIDNum' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetCIDNum("SIP/3050-e3c1", "3050") in new stack Jun 21 14:33:19 WARNING[17128] app_setcidnum.c: SetCIDNum is deprecated, please use Set(CALLERID(number)=value) instead. Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "disca|3097|1") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (disca,3097,1) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "fila_desenvolvimento|3097|1") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (fila_desenvolvimento,3097,1) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'SetLanguage' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing SetLanguage("SIP/3050-e3c1", "br") in new stack Jun 21 14:33:19 WARNING[17128] pbx.c: SetLanguage is deprecated, please use Set(LANGUAGE()=language) instead. Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "3") in new stack Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Goto (fila_desenvolvimento,3097,3) Jun 21 14:33:19 DEBUG[17128] pbx.c: Launching 'Wait' Jun 21 14:33:19 VERBOSE[17128] logger.c: -- Executing Wait("SIP/3050-e3c1", "1") in new stack Jun 21 14:33:19 DEBUG[17129] app_queue.c: Device 'SIP/3050' changed to state '2' (In use) Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetCIDName' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetCIDName("SIP/3050-e3c1", "Fila:desenvolvimento:Ramal Teste") in new stack Jun 21 14:33:20 WARNING[17128] app_setcidname.c: SetCIDName is deprecated, please use Set(CALLERID(name)=value) instead. Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "NOMEFILA=desenvolvimento") in new stack Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "MONITOR_FILENAME=1150911199.0-filadesenvolvimento-3097-in-20060621-143320-3050") in new stack Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'Goto' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing Goto("SIP/3050-e3c1", "8") in new stack Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Goto (fila_desenvolvimento,3097,8) Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "DATAENTRADAFILA=1150911200") in new stack Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "NUMEROCLIENTE=666") in new stack Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "IDTSOLICITANTE=C") in new stack Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing SetVar("SIP/3050-e3c1", "NUMEROTELEFCHAMADO=3097") in new stack Jun 21 14:33:20 DEBUG[17128] pbx.c: Launching 'Queue' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Executing Queue("SIP/3050-e3c1", "desenvolvimento|tr|||600") in new stack Jun 21 14:33:20 DEBUG[17128] app_queue.c: NO QUEUE_PRIO variable found. Using default. Jun 21 14:33:20 DEBUG[17128] app_queue.c: queue: desenvolvimento, options: tr, url: , announce: , expires: 1150911800, priority: 0 Jun 21 14:33:20 DEBUG[17128] app_queue.c: Queue 'desenvolvimento' Join, Channel 'SIP/3050-e3c1', Position '1' Jun 21 14:33:20 VERBOSE[17128] logger.c: Transmitting (NAT) to 172.16.10.124:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKhAmiFQJ1YPzGUAuS;received=172.16.10.124 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" ;tag=as5fb71f40 Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 14:33:20 DEBUG[17128] app_queue.c: It's our turn (SIP/3050-e3c1). Jun 21 14:33:20 DEBUG[17128] app_queue.c: SIP/3050-e3c1 is trying to call a queue member. Jun 21 14:33:20 DEBUG[17128] app_queue.c: Queue with URL=_ Jun 21 14:33:20 DEBUG[17128] app_queue.c: Queue with URL=_ Jun 21 14:33:20 DEBUG[17128] app_queue.c: Queue with URL=_ Jun 21 14:33:20 DEBUG[17128] app_queue.c: Queue with URL=_ Jun 21 14:33:20 DEBUG[17128] app_queue.c: Queue with URL=_ Jun 21 14:33:20 DEBUG[17128] app_queue.c: Trying 'Agent/8003' with metric 0 Jun 21 14:33:20 DEBUG[17128] app_queue.c: Trying 'Agent/3054' with metric 0 Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-12. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable NUMEROTELEFCHAMADO. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-11. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable IDTSOLICITANTE. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-10. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable NUMEROCLIENTE. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-9. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable DATAENTRADAFILA. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-8. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-7. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable MONITOR_FILENAME. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-6. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable NOMEFILA. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-5. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-4. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-3. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-2. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-fila_desenvolvimento-3097-1. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-disca-3097-1. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_out-3097-5. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_out-3097-4. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable CHAMADAINTERNA. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_out-3097-3. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_out-3097-2. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_out-3097-1. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-700. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-602. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable DBGETSTATUS. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-501. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-500. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-406. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable LIMIT_TIMEOUT_FILE. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-405. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable LIMIT_WARNING_FILE. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-404. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable GROUP. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-403. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable TRANSFER_CONTEXT. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-402. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-401. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable NUMERODISCADO. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-400. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-301. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-200. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-2. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable STACK-3050_aux-3097-1. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable SIPCALLID. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable SIPUSERAGENT. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable SIPDOMAIN. Jun 21 14:33:20 DEBUG[17128] channel.c: Not copying variable SIPURI. Jun 21 14:33:20 VERBOSE[17128] logger.c: -- outgoing agentcall, to agent '3054', on 'Local/3054@dac_suporte-0763,1' Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Called Agent/3054 Jun 21 14:33:20 DEBUG[17095] devicestate.c: Changing state for Local/3054@dac_suporte - state 2 (In use) Jun 21 14:33:20 DEBUG[17130] pbx.c: Launching 'Set' Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Executing Set("Local/3054@dac_suporte-0763,2", "GROUP=3054") in new stack Jun 21 14:33:20 DEBUG[17130] pbx.c: Function result is '1' Jun 21 14:33:20 DEBUG[17130] pbx.c: Launching 'NoOp' Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Executing NoOp("Local/3054@dac_suporte-0763,2", "Group: 3054 Count: 1") in new stack Jun 21 14:33:20 DEBUG[17130] pbx.c: Function result is '1' Jun 21 14:33:20 DEBUG[17130] pbx.c: Expression result is '0' Jun 21 14:33:20 DEBUG[17130] pbx.c: Launching 'GotoIf' Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Executing GotoIf("Local/3054@dac_suporte-0763,2", "0 ? 1000") in new stack Jun 21 14:33:20 DEBUG[17130] pbx.c: Not taking any branch Jun 21 14:33:20 DEBUG[17130] pbx.c: Launching 'Goto' Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Executing Goto("Local/3054@dac_suporte-0763,2", "200") in new stack Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Goto (dac_suporte,3054,200) Jun 21 14:33:20 DEBUG[17130] pbx.c: Launching 'SetVar' Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Executing SetVar("Local/3054@dac_suporte-0763,2", "CHAMADAINTERNA=T") in new stack Jun 21 14:33:20 DEBUG[17130] pbx.c: Launching 'Dial' Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Executing Dial("Local/3054@dac_suporte-0763,2", "SIP/3054|15|T") in new stack Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Setting NAT on RTP to 524288 Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable STACK-dac_suporte-3054-201. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable CHAMADAINTERNA. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable STACK-dac_suporte-3054-200. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable STACK-dac_suporte-3054-4. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable STACK-dac_suporte-3054-3. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable STACK-dac_suporte-3054-2. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable GROUP. Jun 21 14:33:20 DEBUG[17130] channel.c: Not copying variable STACK-dac_suporte-3054-1. Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Outgoing Call for 3054 Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Updating call counter for outgoing call Jun 21 14:33:20 VERBOSE[17130] logger.c: We're at 200.196.44.45 port 10278 Jun 21 14:33:20 VERBOSE[17130] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 14:33:20 VERBOSE[17130] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 0: INVITE sip:3054@172.16.10.130;user=phone SIP/2.0 (48) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport (64) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 2: From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (80) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 3: To: (39) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 4: Contact: (33) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 5: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 9: Date: Wed, 21 Jun 2006 17:33:20 GMT (35) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 12: Content-Length: 218 (19) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Header 13: (0) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: v=0 (3) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: o=root 17078 17078 IN IP4 200.196.44.45 (39) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: s=session (9) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: c=IN IP4 200.196.44.45 (22) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: m=audio 10278 RTP/AVP 8 101 (27) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 14:33:20 DEBUG[17130] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 21 14:33:20 VERBOSE[17130] logger.c: 13 headers, 10 lines Jun 21 14:33:20 VERBOSE[17130] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: INVITE sip:3054@172.16.10.130;user=phone SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: Contact: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 21 Jun 2006 17:33:20 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 218 v=0 o=root 17078 17078 IN IP4 200.196.44.45 s=session c=IN IP4 200.196.44.45 t=0 0 m=audio 10278 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 14:33:20 DEBUG[17130] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #25 Jun 21 14:33:20 VERBOSE[17130] logger.c: -- Called 3054 Jun 21 14:33:20 DEBUG[17130] channel.c: Set channel SIP/3054-adae to read format alaw Jun 21 14:33:20 DEBUG[17130] channel.c: Set channel Local/3054@dac_suporte-0763,2 to write format alaw Jun 21 14:33:20 DEBUG[17130] channel.c: Set channel Local/3054@dac_suporte-0763,2 to read format alaw Jun 21 14:33:20 DEBUG[17130] channel.c: Set channel SIP/3054-adae to write format alaw Jun 21 14:33:20 DEBUG[17131] app_queue.c: Device 'Local/3054@dac_suporte' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:20 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 102 INVITE User-Agent: Grandstream BT100 1.0.6.7 Content-Length: 0 Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport (64) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 2: From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (80) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 3: To: (39) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 4: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 6: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 7: Content-Length: 0 (17) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 8: (0) Jun 21 14:33:20 VERBOSE[17112] logger.c: --- (8 headers 0 lines)Jun 21 14:33:20 VERBOSE[17112] logger.c: --- (8 headers 0 lines)--- Jun 21 14:33:20 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag Our tag: as7fd943f4 Jun 21 14:33:20 DEBUG[17112] chan_sip.c: *** SIP TIMER: Cancelling retransmission #25 - INVITE (got response) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '358e288144c20d76777826511b917d82@200.196.44.45' Request 102: Found Jun 21 14:33:20 DEBUG[17112] chan_sip.c: SIP response 100 to standard invite Jun 21 14:33:20 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 102 INVITE User-Agent: Grandstream BT100 1.0.6.7 Content-Length: 0 Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport (64) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 2: From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (80) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=f4c05af8c7db954e (60) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 4: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 6: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 7: Content-Length: 0 (17) Jun 21 14:33:20 DEBUG[17112] chan_sip.c: Header 8: (0) Jun 21 14:33:20 VERBOSE[17112] logger.c: --- (8 headers 0 lines)Jun 21 14:33:20 VERBOSE[17112] logger.c: --- (8 headers 0 lines)--- Jun 21 14:33:20 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag Our tag: as7fd943f4 Jun 21 14:33:20 DEBUG[17112] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '358e288144c20d76777826511b917d82@200.196.44.45' Request 102: Found Jun 21 14:33:20 DEBUG[17112] chan_sip.c: SIP response 180 to standard invite Jun 21 14:33:20 VERBOSE[17130] logger.c: -- SIP/3054-adae is ringing Jun 21 14:33:20 DEBUG[17095] chan_sip.c: Checking device state for peer 3054 Jun 21 14:33:20 DEBUG[17095] devicestate.c: Changing state for SIP/3054 - state 6 (Ringing) Jun 21 14:33:20 VERBOSE[17128] logger.c: -- Agent/3054 is ringing Jun 21 14:33:20 DEBUG[17132] app_queue.c: Device 'SIP/3054' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jun 21 14:33:23 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 102 INVITE User-Agent: Grandstream BT100 1.0.6.7 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Supported: replaces Content-Length: 158 v=0 o=3054 8000 8000 IN IP4 172.16.10.130 s=SIP Call c=IN IP4 172.16.10.130 t=0 0 m=audio 10000 RTP/AVP 8 a=sendrecv a=rtpmap:8 PCMA/8000 a=ptime:20 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK3b3dbfae;rport (64) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 2: From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (80) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=f4c05af8c7db954e (60) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 4: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 6: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 7: Contact: (44) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 9: Content-Type: application/sdp (29) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 10: Supported: replaces (19) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 11: Content-Length: 158 (19) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 12: (0) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: o=3054 8000 8000 IN IP4 172.16.10.130 (37) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: s=SIP Call (10) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: c=IN IP4 172.16.10.130 (22) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: m=audio 10000 RTP/AVP 8 (23) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: a=sendrecv (10) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Line: a=ptime:20 (10) Jun 21 14:33:23 VERBOSE[17112] logger.c: --- (12 headers 9 lines)Jun 21 14:33:23 VERBOSE[17112] logger.c: --- (12 headers 9 lines)--- Jun 21 14:33:23 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Acked pending invite 102 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Stopping retransmission on '358e288144c20d76777826511b917d82@200.196.44.45' of Request 102: Match Found Jun 21 14:33:23 DEBUG[17112] chan_sip.c: SIP response 200 to standard invite Jun 21 14:33:23 VERBOSE[17112] logger.c: Found RTP audio format 8 Jun 21 14:33:23 VERBOSE[17112] logger.c: Peer audio RTP is at port 172.16.10.130:10000 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Peer audio RTP is at port 172.16.10.130:10000 Jun 21 14:33:23 VERBOSE[17112] logger.c: Found description format PCMA Jun 21 14:33:23 VERBOSE[17112] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Jun 21 14:33:23 VERBOSE[17112] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: build_route: Contact hop: Jun 21 14:33:23 VERBOSE[17112] logger.c: list_route: hop: Jun 21 14:33:23 VERBOSE[17112] logger.c: set_destination: Parsing for address/port to send to Jun 21 14:33:23 VERBOSE[17112] logger.c: set_destination: set destination to 172.16.10.130, port 5060 Jun 21 14:33:23 VERBOSE[17112] logger.c: Transmitting (NAT) to 172.16.10.130:5060: ACK sip:3054@172.16.10.130;user=phone SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK22b7e92f;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Contact: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 14:33:23 VERBOSE[17130] logger.c: -- SIP/3054-adae answered Local/3054@dac_suporte-0763,2 Jun 21 14:33:23 DEBUG[17130] channel.c: Set channel Local/3054@dac_suporte-0763,2 to read format alaw Jun 21 14:33:23 DEBUG[17130] channel.c: Set channel SIP/3054-adae to write format alaw Jun 21 14:33:23 DEBUG[17130] channel.c: Set channel SIP/3054-adae to read format alaw Jun 21 14:33:23 DEBUG[17130] channel.c: Set channel Local/3054@dac_suporte-0763,2 to write format alaw Jun 21 14:33:23 DEBUG[17095] chan_sip.c: Checking device state for peer 3054 Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for SIP/3054 - state 2 (In use) Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for Local/3054@dac_suporte - state 2 (In use) Jun 21 14:33:23 DEBUG[17128] app_queue.c: Dunno what to do with control type -1 Jun 21 14:33:23 VERBOSE[17128] logger.c: -- Agent/3054 answered SIP/3050-e3c1 Jun 21 14:33:23 DEBUG[17128] channel.c: Set channel SIP/3050-e3c1 to read format alaw Jun 21 14:33:23 DEBUG[17128] channel.c: Set channel Agent/3054 to write format alaw Jun 21 14:33:23 DEBUG[17128] channel.c: Set channel Agent/3054 to read format alaw Jun 21 14:33:23 DEBUG[17128] channel.c: Set channel SIP/3050-e3c1 to write format alaw Jun 21 14:33:23 DEBUG[17128] chan_sip.c: sip_answer(SIP/3050-e3c1) Jun 21 14:33:23 VERBOSE[17128] logger.c: We're at 200.196.44.45 port 14414 Jun 21 14:33:23 VERBOSE[17128] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 14:33:23 VERBOSE[17128] logger.c: Reliably Transmitting (NAT) to 172.16.10.124:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKhAmiFQJ1YPzGUAuS;received=172.16.10.124 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" ;tag=as5fb71f40 Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 162 v=0 o=root 17078 17078 IN IP4 200.196.44.45 s=session c=IN IP4 200.196.44.45 t=0 0 m=audio 14414 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- Jun 21 14:33:23 DEBUG[17128] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #27 Jun 21 14:33:23 DEBUG[17133] app_queue.c: Device 'SIP/3054' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:23 DEBUG[17134] app_queue.c: Device 'Local/3054@dac_suporte' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for Local/3054@dac_suporte - state 2 (In use) Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for Agent/3054 - state 3 (Busy) Jun 21 14:33:23 DEBUG[17095] chan_sip.c: Checking device state for peer 3050 Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for SIP/3050 - state 2 (In use) Jun 21 14:33:23 DEBUG[17135] app_queue.c: Device 'Local/3054@dac_suporte' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:23 DEBUG[17136] app_queue.c: Device 'Agent/3054' changed to state '3' (Busy) Jun 21 14:33:23 DEBUG[17137] app_queue.c: Device 'SIP/3050' changed to state '2' (In use) Jun 21 14:33:23 DEBUG[17130] channel.c: Planning to masquerade channel SIP/3054-adae into the structure of Local/3054@dac_suporte-0763,1 Jun 21 14:33:23 DEBUG[17130] channel.c: Done planning to masquerade channel SIP/3054-adae into the structure of Local/3054@dac_suporte-0763,1 Jun 21 14:33:23 DEBUG[17130] chan_local.c: Not posting to queue since already masked on 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17128] channel.c: Actually Masquerading SIP/3054-adae(6) into the structure of Local/3054@dac_suporte-0763,1(6) Jun 21 14:33:23 DEBUG[17128] channel.c: Got clone lock for masquerade on 'SIP/3054-adae' at 0x9f2c62c Jun 21 14:33:23 DEBUG[17128] channel.c: Set channel SIP/3054-adae to write format alaw Jun 21 14:33:23 DEBUG[17128] channel.c: Set channel SIP/3054-adae to read format alaw Jun 21 14:33:23 DEBUG[17128] channel.c: Putting channel SIP/3054-adae in 8/8 formats Jun 21 14:33:23 DEBUG[17128] channel.c: Released clone lock on 'Local/3054@dac_suporte-0763,1' Jun 21 14:33:23 DEBUG[17128] channel.c: Done Masquerading SIP/3054-adae (6) Jun 21 14:33:23 DEBUG[17128] chan_agent.c: Bridge on 'SIP/3054-adae' being set to 'Agent/3054' (3) Jun 21 14:33:23 DEBUG[17130] channel.c: Didn't get a frame from channel: Local/3054@dac_suporte-0763,1 Jun 21 14:33:23 DEBUG[17130] channel.c: Bridge stops bridging channels Local/3054@dac_suporte-0763,2 and Local/3054@dac_suporte-0763,1 Jun 21 14:33:23 DEBUG[17130] channel.c: Hanging up zombie 'Local/3054@dac_suporte-0763,1' Jun 21 14:33:23 DEBUG[17130] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jun 21 14:33:23 DEBUG[17130] pbx.c: Spawn extension (dac_suporte,3054,201) exited non-zero on 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17128] rtp.c: Ooh, format changed from unknown to alaw Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] channel.c: Avoiding initial deadlock for 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 WARNING[17095] channel.c: Avoided initial deadlock for '0x9f25f80', 10 retries! Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for Local/3054@dac_suporte - state 0 (Unknown) Jun 21 14:33:23 DEBUG[17138] app_queue.c: Device 'Local/3054@dac_suporte' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jun 21 14:33:23 DEBUG[17130] channel.c: Hanging up channel 'Local/3054@dac_suporte-0763,2' Jun 21 14:33:23 DEBUG[17095] devicestate.c: Changing state for Local/3054@dac_suporte - state 0 (Unknown) Jun 21 14:33:23 DEBUG[17139] app_queue.c: Device 'Local/3054@dac_suporte' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jun 21 14:33:23 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.124:5060: ACK sip:3097@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKZZB2HIXjVhctTjg0 Max-Forwards: 70 User-Agent: SOYO.SIP V1.49.002 CFG0 From: "3050" ;tag=suzM66WNr09urc4w To: "3097" ;tag=as5fb71f40 Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 Contact: Proxy-Authorization: Digest username="3050", realm="asterisk", nonce="289acd1a", uri="sip:3097@200.196.44.45", response="4728427e019142af5c4c915a0a6787df", algorithm=MD5 CSeq: 2 ACK Content-Length: 0 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 0: ACK sip:3097@200.196.44.45 SIP/2.0 (34) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.124:5060;branch=z9hG4bKZZB2HIXjVhctTjg0 (66) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 2: Max-Forwards: 70 (16) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 3: User-Agent: SOYO.SIP V1.49.002 CFG0 (36) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 4: From: "3050" ;tag=suzM66WNr09urc4w (72) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 5: To: "3097" ;tag=as5fb71f40 (64) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 6: Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 (39) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 7: Contact: (38) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 8: Proxy-Authorization: Digest username="3050", realm="asterisk", nonce="289acd1a", uri="sip:3097@200.196.44.45", response="4728427e019142af5c4c915a0a6787df", algorithm=MD5 (169) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 9: CSeq: 2 ACK (11) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:23 VERBOSE[17112] logger.c: --- (11 headers 0 lines)Jun 21 14:33:23 VERBOSE[17112] logger.c: --- (11 headers 0 lines)--- Jun 21 14:33:23 DEBUG[17112] chan_sip.c: = No match Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: = Found Their Call ID: XwwleZrXLRTRbZSJ@172.16.10.124 Their Tag suzM66WNr09urc4w Our tag: as5fb71f40 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 14:33:23 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #27 Jun 21 14:33:23 DEBUG[17112] chan_sip.c: Stopping retransmission on 'XwwleZrXLRTRbZSJ@172.16.10.124' of Response 2: Match Found Jun 21 14:33:23 DEBUG[17128] rtp.c: Ooh, format changed from unknown to alaw Jun 21 14:33:26 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: INVITE sip:3050@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKd2cdb59fa52aaceb From: ;tag=f4c05af8c7db954e To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 Contact: Supported: replaces Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 11526 INVITE User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Content-Length: 176 v=0 o=3054 8000 8001 IN IP4 172.16.10.130 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 10000 RTP/AVP 8 0 a=sendonly a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=ptime:20 Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 0: INVITE sip:3050@200.196.44.45 SIP/2.0 (37) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKd2cdb59fa52aaceb (61) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 2: From: ;tag=f4c05af8c7db954e (62) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 3: To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (78) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 5: Supported: replaces (19) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 6: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 7: CSeq: 11526 INVITE (18) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 8: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 9: Max-Forwards: 70 (16) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 10: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 12: Content-Length: 176 (19) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 13: (0) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: o=3054 8000 8001 IN IP4 172.16.10.130 (37) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: s=SIP Call (10) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: c=IN IP4 0.0.0.0 (16) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: m=audio 10000 RTP/AVP 8 0 (25) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: a=sendonly (10) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Line: a=ptime:20 (10) Jun 21 14:33:26 VERBOSE[17112] logger.c: --- (13 headers 10 lines)Jun 21 14:33:26 VERBOSE[17112] logger.c: --- (13 headers 10 lines)--- Jun 21 14:33:26 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:26 DEBUG[17112] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Begin: parsing SIP "Supported: replaces" Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Found SIP option: -replaces- Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Matched SIP option: replaces Jun 21 14:33:26 DEBUG[17112] chan_sip.c: * SIP extension value: 1 for call 358e288144c20d76777826511b917d82@200.196.44.45 Jun 21 14:33:26 VERBOSE[17112] logger.c: Using INVITE request as basis request - 358e288144c20d76777826511b917d82@200.196.44.45 Jun 21 14:33:26 VERBOSE[17112] logger.c: Sending to 172.16.10.130 : 5060 (NAT) Jun 21 14:33:26 VERBOSE[17112] logger.c: Found RTP audio format 8 Jun 21 14:33:26 VERBOSE[17112] logger.c: Found RTP audio format 0 Jun 21 14:33:26 VERBOSE[17112] logger.c: Peer audio RTP is at port 0.0.0.0:10000 Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Peer audio RTP is at port 0.0.0.0:10000 Jun 21 14:33:26 VERBOSE[17112] logger.c: Found description format PCMA Jun 21 14:33:26 VERBOSE[17112] logger.c: Found description format PCMU Jun 21 14:33:26 VERBOSE[17112] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Jun 21 14:33:26 VERBOSE[17112] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Jun 21 14:33:26 DEBUG[17112] chan_agent.c: Asked for bridged channel on 'SIP/3054-adae'/'Agent/3054', returning 'SIP/3050-e3c1' Jun 21 14:33:26 DEBUG[17112] channel.c: Set channel SIP/3050-e3c1 to write format slin Jun 21 14:33:26 VERBOSE[17112] logger.c: -- Started music on hold, class 'planetarium', on channel 'SIP/3050-e3c1' Jun 21 14:33:26 DEBUG[17112] channel.c: Scheduling timer at 160 sample intervals Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Got a SIP re-invite for call 358e288144c20d76777826511b917d82@200.196.44.45 Jun 21 14:33:26 VERBOSE[17112] logger.c: We're at 200.196.44.45 port 10278 Jun 21 14:33:26 VERBOSE[17112] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 14:33:26 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKd2cdb59fa52aaceb;received=172.16.10.130 From: ;tag=f4c05af8c7db954e To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 11526 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 162 v=0 o=root 17078 17079 IN IP4 200.196.44.45 s=session c=IN IP4 200.196.44.45 t=0 0 m=audio 10278 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- Jun 21 14:33:26 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #28 Jun 21 14:33:26 DEBUG[17128] channel.c: Generator got voice, switching to phase locked mode Jun 21 14:33:26 DEBUG[17128] channel.c: Scheduling timer at 0 sample intervals Jun 21 14:33:26 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: ACK sip:3050@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKc52df9ee0789815b From: ;tag=f4c05af8c7db954e To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 Contact: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 11526 ACK User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 0: ACK sip:3050@200.196.44.45 SIP/2.0 (34) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKc52df9ee0789815b (61) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 2: From: ;tag=f4c05af8c7db954e (62) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 3: To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (78) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 5: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 6: CSeq: 11526 ACK (15) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 7: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 9: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:26 VERBOSE[17112] logger.c: --- (11 headers 0 lines)Jun 21 14:33:26 VERBOSE[17112] logger.c: --- (11 headers 0 lines)--- Jun 21 14:33:26 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:26 DEBUG[17112] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 14:33:26 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #28 Jun 21 14:33:26 DEBUG[17112] chan_sip.c: Stopping retransmission on '358e288144c20d76777826511b917d82@200.196.44.45' of Response 11526: Match Found Jun 21 14:33:29 DEBUG[17095] chan_iax2.c: Checking device state for device 3051 Jun 21 14:33:29 DEBUG[17095] chan_iax2.c: iax2_devicestate(3051): Found peer. What's device state of 3051? addr=1896485036, defaddr=0 maxms=2000, lastms=40 Jun 21 14:33:29 DEBUG[17095] devicestate.c: Changing state for IAX2/3051 - state 1 (Not in use) Jun 21 14:33:29 DEBUG[17142] app_queue.c: Device 'IAX2/3051' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 21 14:33:29 DEBUG[17101] db.c: Unable to find key 'si-000fd3000a41' in family 'iax/provisioning/cache' Jun 21 14:33:29 DEBUG[17095] chan_iax2.c: Checking device state for device 3051 Jun 21 14:33:29 DEBUG[17095] chan_iax2.c: iax2_devicestate(3051): Found peer. What's device state of 3051? addr=1896485036, defaddr=0 maxms=2000, lastms=40 Jun 21 14:33:29 DEBUG[17095] devicestate.c: Changing state for IAX2/3051 - state 1 (Not in use) Jun 21 14:33:29 DEBUG[17143] app_queue.c: Device 'IAX2/3051' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 21 14:33:29 DEBUG[17101] iax2-provision.c: Unable to create provisioning packet for 'si-000fd3000a41' Jun 21 14:33:30 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: INVITE sip:3053@pfdesenv.planetarium.com.br;user=phone SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf23605d7cbdcb78c From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: Contact: Supported: replaces Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3053 INVITE User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Content-Length: 182 v=0 o=3054 8001 8000 IN IP4 172.16.10.130 s=SIP Call c=IN IP4 172.16.10.130 t=0 0 m=audio 10002 RTP/AVP 8 0 a=sendrecv a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=ptime:30 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 0: INVITE sip:3053@pfdesenv.planetarium.com.br;user=phone SIP/2.0 (62) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf23605d7cbdcb78c (61) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (95) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 3: To: (53) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 5: Supported: replaces (19) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 6: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 7: CSeq: 3053 INVITE (17) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 8: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 9: Max-Forwards: 70 (16) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 10: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 12: Content-Length: 182 (19) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 13: (0) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: o=3054 8001 8000 IN IP4 172.16.10.130 (37) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: s=SIP Call (10) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: c=IN IP4 172.16.10.130 (22) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: m=audio 10002 RTP/AVP 8 0 (25) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=sendrecv (10) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=ptime:30 (10) Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (13 headers 10 lines)Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (13 headers 10 lines)--- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: = No match Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: = No match Their Call ID: XwwleZrXLRTRbZSJ@172.16.10.124 Their Tag suzM66WNr09urc4w Our tag: as5fb71f40 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Allocating new SIP dialog for e6ef9d214dd27545@172.16.10.130 - INVITE (With RTP) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Begin: parsing SIP "Supported: replaces" Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Found SIP option: -replaces- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Matched SIP option: replaces Jun 21 14:33:30 DEBUG[17112] chan_sip.c: * SIP extension value: 1 for call e6ef9d214dd27545@172.16.10.130 Jun 21 14:33:30 VERBOSE[17112] logger.c: Using INVITE request as basis request - e6ef9d214dd27545@172.16.10.130 Jun 21 14:33:30 VERBOSE[17112] logger.c: Sending to 172.16.10.130 : 5060 (non-NAT) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Setting NAT on RTP to 524288 Jun 21 14:33:30 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf23605d7cbdcb78c;received=172.16.10.130 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as0b3a59e3 Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3053 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="6e09bc3c" Content-Length: 0 --- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #29 Jun 21 14:33:30 VERBOSE[17112] logger.c: Scheduling destruction of call 'e6ef9d214dd27545@172.16.10.130' in 15000 ms Jun 21 14:33:30 VERBOSE[17112] logger.c: Found user '3054' Jun 21 14:33:30 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: ACK sip:3053@pfdesenv.planetarium.com.br;user=phone SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf23605d7cbdcb78c From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as0b3a59e3 Contact: Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3053 ACK User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 0: ACK sip:3053@pfdesenv.planetarium.com.br;user=phone SIP/2.0 (59) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf23605d7cbdcb78c (61) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (95) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=as0b3a59e3 (68) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 5: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 6: CSeq: 3053 ACK (14) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 7: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 9: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (11 headers 0 lines)Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (11 headers 0 lines)--- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: = Found Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as0b3a59e3 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 14:33:30 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #29 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Stopping retransmission on 'e6ef9d214dd27545@172.16.10.130' of Response 3053: Match Found Jun 21 14:33:30 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: INVITE sip:3053@pfdesenv.planetarium.com.br;user=phone SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK23f9dd21ff3b5248 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: Contact: Supported: replaces Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@pfdesenv.planetarium.com.br;user=phone", nonce="6e09bc3c", response="72dd6e26e92d43108534f55f6f713c0c" Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3054 INVITE User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Content-Length: 182 v=0 o=3054 8001 8001 IN IP4 172.16.10.130 s=SIP Call c=IN IP4 172.16.10.130 t=0 0 m=audio 10002 RTP/AVP 8 0 a=sendrecv a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=ptime:30 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 0: INVITE sip:3053@pfdesenv.planetarium.com.br;user=phone SIP/2.0 (62) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK23f9dd21ff3b5248 (61) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (95) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 3: To: (53) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 5: Supported: replaces (19) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 6: Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@pfdesenv.planetarium.com.br;user=phone", nonce="6e09bc3c", response="72dd6e26e92d43108534f55f6f713c0c" (194) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 7: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 8: CSeq: 3054 INVITE (17) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 9: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 10: Max-Forwards: 70 (16) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 11: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 12: Content-Type: application/sdp (29) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 13: Content-Length: 182 (19) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 14: (0) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: o=3054 8001 8001 IN IP4 172.16.10.130 (37) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: s=SIP Call (10) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: c=IN IP4 172.16.10.130 (22) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: m=audio 10002 RTP/AVP 8 0 (25) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=sendrecv (10) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Line: a=ptime:30 (10) Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (14 headers 10 lines)Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (14 headers 10 lines)--- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: = Found Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as0b3a59e3 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 14:33:30 VERBOSE[17112] logger.c: Using INVITE request as basis request - e6ef9d214dd27545@172.16.10.130 Jun 21 14:33:30 VERBOSE[17112] logger.c: Sending to 172.16.10.130 : 5060 (NAT) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Setting NAT on RTP to 524288 Jun 21 14:33:30 VERBOSE[17112] logger.c: Found user '3054' Jun 21 14:33:30 VERBOSE[17112] logger.c: Found RTP audio format 8 Jun 21 14:33:30 VERBOSE[17112] logger.c: Found RTP audio format 0 Jun 21 14:33:30 VERBOSE[17112] logger.c: Peer audio RTP is at port 172.16.10.130:10002 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Peer audio RTP is at port 172.16.10.130:10002 Jun 21 14:33:30 VERBOSE[17112] logger.c: Found description format PCMA Jun 21 14:33:30 VERBOSE[17112] logger.c: Found description format PCMU Jun 21 14:33:30 VERBOSE[17112] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Jun 21 14:33:30 VERBOSE[17112] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Checking SIP call limits for device 3054 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Updating call counter for incoming call Jun 21 14:33:30 VERBOSE[17112] logger.c: Looking for 3053 in 3054_aux (domain pfdesenv.planetarium.com.br) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: build_route: Contact hop: Jun 21 14:33:30 VERBOSE[17112] logger.c: list_route: hop: Jun 21 14:33:30 VERBOSE[17112] logger.c: Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK23f9dd21ff3b5248;received=172.16.10.130 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3054 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 14:33:30 DEBUG[17095] chan_sip.c: Checking device state for peer 3054 Jun 21 14:33:30 DEBUG[17095] devicestate.c: Changing state for SIP/3054 - state 2 (In use) Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '0' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "0 ? 1000") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Not taking any branch Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '1' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "1 ? 200:400") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_aux,3053,200) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBget' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBget("SIP/3054-bb66", "ramalbloqueado=BLOQUEIORAMAL/3054") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: varname=ramalbloqueado, family=BLOQUEIORAMAL, key=3054 Jun 21 14:33:30 DEBUG[17144] db.c: Unable to find key '3054' in family 'BLOQUEIORAMAL' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: Value not found in database. Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "400") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_aux,3053,400) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "NUMERODISCADO=3053") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '0' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "0 ? 404") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Not taking any branch Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "TRANSFER_CONTEXT=3054_aux") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Set' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Set("SIP/3054-bb66", "GROUP=3054") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "LIMIT_WARNING_FILE=beep") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "LIMIT_TIMEOUT_FILE=beep5") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "500") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_aux,3053,500) Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '0' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "0 ? 700") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Not taking any branch Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBget' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBget("SIP/3054-bb66", "GRAVACAOCHAMADASAIDA=GRAVACAOCHAMADASAIDA/3054") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: varname=GRAVACAOCHAMADASAIDA, family=GRAVACAOCHAMADASAIDA, key=3054 Jun 21 14:33:30 DEBUG[17144] db.c: Unable to find key '3054' in family 'GRAVACAOCHAMADASAIDA' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: Value not found in database. Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "700") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_aux,3053,700) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "3054_out|3053|1") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_out,3053,1) Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '1' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "1 ? 2:5") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_out,3053,2) Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '1' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "1 ? 3:5") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3054_out,3053,3) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "CHAMADAINTERNA=T") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetCIDNum' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetCIDNum("SIP/3054-bb66", "3054") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "disca|3053|1") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (disca,3053,1) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "3053_in|3053|1") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3053_in,3053,1) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "1000") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (3053_in,3053,1000) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Macro' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Macro("SIP/3054-bb66", "atende|SIP/3053|3053") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetLanguage' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetLanguage("SIP/3054-bb66", "br") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "DIALTECHRAMAL=SIP/3053") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "100") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,100) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBget' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBget("SIP/3054-bb66", "RAMALREDIR=SIGAME/3053") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: varname=RAMALREDIR, family=SIGAME, key=3053 Jun 21 14:33:30 DEBUG[17144] db.c: Unable to find key '3053' in family 'SIGAME' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: Value not found in database. Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "s|150") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,150) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBget' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBget("SIP/3054-bb66", "RAMALREDIR=SIGAMEEXTERNO/3053") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: varname=RAMALREDIR, family=SIGAMEEXTERNO, key=3053 Jun 21 14:33:30 DEBUG[17144] db.c: Unable to find key '3053' in family 'SIGAMEEXTERNO' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: Value not found in database. Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "s|300") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,300) Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '1' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "1 ? 301:302") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,301) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'SetVar' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing SetVar("SIP/3054-bb66", "RAMALFINAL=3053") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBput' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBput("SIP/3054-bb66", "ULTIMOCHAMADO/3053=3054") in new stack Jun 21 14:33:30 WARNING[17144] app_db.c: This application has been deprecated, please use the ${DB(family/key)} function instead. Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBput: family=ULTIMOCHAMADO, key=3053, value=3054 Jun 21 14:33:30 DEBUG[17145] app_queue.c: Device 'SIP/3054' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '0' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "0 ? 304:305") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,305) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "350") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,350) Jun 21 14:33:30 DEBUG[17144] pbx.c: Expression result is '1' Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'GotoIf' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing GotoIf("SIP/3054-bb66", "1 ? 500") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,500) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Set' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Set("SIP/3054-bb66", "OUTBOUND_GROUP=3053") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBget' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBget("SIP/3054-bb66", "MAXLIGACOES=MAXLIGACOES/3053") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: varname=MAXLIGACOES, family=MAXLIGACOES, key=3053 Jun 21 14:33:30 DEBUG[17144] db.c: Unable to find key '3053' in family 'MAXLIGACOES' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: Value not found in database. Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "s|700") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,700) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'StopMonitor' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing StopMonitor("SIP/3054-bb66", "") in new stack Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'DBget' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing DBget("SIP/3054-bb66", "GRAVACAOCHAMADA=GRAVACAOCHAMADA/3053") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: varname=GRAVACAOCHAMADA, family=GRAVACAOCHAMADA, key=3053 Jun 21 14:33:30 DEBUG[17144] db.c: Unable to find key '3053' in family 'GRAVACAOCHAMADA' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- DBget: Value not found in database. Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Goto' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Goto("SIP/3054-bb66", "s|900") in new stack Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Goto (macro-atende,s,900) Jun 21 14:33:30 DEBUG[17144] pbx.c: Launching 'Dial' Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Executing Dial("SIP/3054-bb66", "SIP/3053|30|tT") in new stack Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Setting NAT on RTP to 0 Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-900. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable MACRO_DEPTH. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-802. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable DBGETSTATUS. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-701. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-700. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-602. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-501. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable OUTBOUND_GROUP. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-500. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-350. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-305. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-303. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-302. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable RAMALFINAL. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-301. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-300. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-251. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-150. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-201. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-100. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-3. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable DIALTECHRAMAL. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-2. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-macro-atende-s-1. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable ARG2. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable ARG1. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable MACRO_PRIORITY. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable MACRO_CONTEXT. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable MACRO_EXTEN. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3053_in-3053-1000. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3053_in-3053-1. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-disca-3053-1. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_out-3053-5. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_out-3053-4. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable CHAMADAINTERNA. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_out-3053-3. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_out-3053-2. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_out-3053-1. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-700. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-602. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-501. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-500. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-406. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable LIMIT_TIMEOUT_FILE. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-405. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable LIMIT_WARNING_FILE. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-404. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable GROUP. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-403. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable TRANSFER_CONTEXT. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-402. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-401. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable NUMERODISCADO. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-400. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-301. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-200. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-2. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable STACK-3054_aux-3053-1. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable SIPCALLID. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable SIPUSERAGENT. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable SIPDOMAIN. Jun 21 14:33:30 DEBUG[17144] channel.c: Not copying variable SIPURI. Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Outgoing Call for 3053 Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Updating call counter for outgoing call Jun 21 14:33:30 VERBOSE[17144] logger.c: We're at 200.196.44.45 port 16010 Jun 21 14:33:30 VERBOSE[17144] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 14:33:30 VERBOSE[17144] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 0: INVITE sip:3053@172.16.10.112:5060 SIP/2.0 (42) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport (64) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 2: From: "Ramal 3054" ;tag=as543f517a (58) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 3: To: (33) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 4: Contact: (33) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 5: Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 (55) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 9: Date: Wed, 21 Jun 2006 17:33:30 GMT (35) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 12: Content-Length: 218 (19) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Header 13: (0) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: v=0 (3) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: o=root 17078 17078 IN IP4 200.196.44.45 (39) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: s=session (9) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: c=IN IP4 200.196.44.45 (22) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: m=audio 16010 RTP/AVP 8 101 (27) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 21 14:33:30 DEBUG[17144] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 21 14:33:30 VERBOSE[17144] logger.c: 13 headers, 10 lines Jun 21 14:33:30 VERBOSE[17144] logger.c: Reliably Transmitting (no NAT) to 172.16.10.112:5060: INVITE sip:3053@172.16.10.112:5060 SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport From: "Ramal 3054" ;tag=as543f517a To: Contact: Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 21 Jun 2006 17:33:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 218 v=0 o=root 17078 17078 IN IP4 200.196.44.45 s=session c=IN IP4 200.196.44.45 t=0 0 m=audio 16010 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 21 14:33:30 DEBUG[17144] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #31 Jun 21 14:33:30 VERBOSE[17144] logger.c: -- Called 3053 Jun 21 14:33:30 DEBUG[17144] channel.c: Set channel SIP/3053-89ad to read format alaw Jun 21 14:33:30 DEBUG[17144] channel.c: Set channel SIP/3054-bb66 to write format alaw Jun 21 14:33:30 DEBUG[17144] channel.c: Set channel SIP/3054-bb66 to read format alaw Jun 21 14:33:30 DEBUG[17144] channel.c: Set channel SIP/3053-89ad to write format alaw Jun 21 14:33:30 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.112:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport From: "Ramal 3054" ;tag=as543f517a To: ;tag=42D3DD8F-325CCD70 CSeq: 102 INVITE Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Contact: User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.6.6.0036 Content-Length: 0 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport (64) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal 3054" ;tag=as543f517a (58) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=42D3DD8F-325CCD70 (55) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 5: Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 (55) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 6: Contact: (38) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.6.6.0036 (54) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 8: Content-Length: 0 (17) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 9: (0) Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (9 headers 0 lines)Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (9 headers 0 lines)--- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: = Found Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag Our tag: as543f517a Jun 21 14:33:30 DEBUG[17112] chan_sip.c: *** SIP TIMER: Cancelling retransmission #31 - INVITE (got response) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '66137c0836bdbc261d4fd80359ebf035@200.196.44.45' Request 102: Found Jun 21 14:33:30 DEBUG[17112] chan_sip.c: SIP response 100 to standard invite Jun 21 14:33:30 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.112:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport From: "Ramal 3054" ;tag=as543f517a To: ;tag=42D3DD8F-325CCD70 CSeq: 102 INVITE Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Contact: User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.6.6.0036 Allow-Events: talk,hold,conference Content-Length: 0 Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport (64) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal 3054" ;tag=as543f517a (58) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=42D3DD8F-325CCD70 (55) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 5: Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 (55) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 6: Contact: (38) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.6.6.0036 (54) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 8: Allow-Events: talk,hold,conference (34) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 9: Content-Length: 0 (17) Jun 21 14:33:30 DEBUG[17112] chan_sip.c: Header 10: (0) Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (10 headers 0 lines)Jun 21 14:33:30 VERBOSE[17112] logger.c: --- (10 headers 0 lines)--- Jun 21 14:33:30 DEBUG[17112] chan_sip.c: = Found Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:30 DEBUG[17112] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '66137c0836bdbc261d4fd80359ebf035@200.196.44.45' Request 102: Found Jun 21 14:33:30 DEBUG[17112] chan_sip.c: SIP response 180 to standard invite Jun 21 14:33:30 VERBOSE[17144] logger.c: -- SIP/3053-89ad is ringing Jun 21 14:33:30 VERBOSE[17144] logger.c: Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK23f9dd21ff3b5248;received=172.16.10.130 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as78451bbb Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3054 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 14:33:30 DEBUG[17095] chan_sip.c: Checking device state for peer 3053 Jun 21 14:33:30 DEBUG[17095] devicestate.c: Changing state for SIP/3053 - state 6 (Ringing) Jun 21 14:33:30 DEBUG[17146] app_queue.c: Device 'SIP/3053' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jun 21 14:33:33 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.112:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport From: "Ramal 3054" ;tag=as543f517a To: ;tag=42D3DD8F-325CCD70 CSeq: 102 INVITE Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.6.6.0036 Content-Type: application/sdp Content-Length: 187 v=0 o=- 979442733 979442733 IN IP4 172.16.10.112 s=Polycom IP Phone c=IN IP4 172.16.10.112 t=0 0 m=audio 2236 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK16a369c8;rport (64) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal 3054" ;tag=as543f517a (58) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=42D3DD8F-325CCD70 (55) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 5: Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 (55) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 6: Contact: (38) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.6.6.0036 (54) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 9: Content-Type: application/sdp (29) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 187 (19) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: o=- 979442733 979442733 IN IP4 172.16.10.112 (44) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: s=Polycom IP Phone (18) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: c=IN IP4 172.16.10.112 (22) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: m=audio 2236 RTP/AVP 8 101 (26) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 21 14:33:33 VERBOSE[17112] logger.c: --- (11 headers 8 lines)Jun 21 14:33:33 VERBOSE[17112] logger.c: --- (11 headers 8 lines)--- Jun 21 14:33:33 DEBUG[17112] chan_sip.c: = Found Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Acked pending invite 102 Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Stopping retransmission on '66137c0836bdbc261d4fd80359ebf035@200.196.44.45' of Request 102: Match Found Jun 21 14:33:33 DEBUG[17112] chan_sip.c: SIP response 200 to standard invite Jun 21 14:33:33 VERBOSE[17112] logger.c: Found RTP audio format 8 Jun 21 14:33:33 VERBOSE[17112] logger.c: Found RTP audio format 101 Jun 21 14:33:33 VERBOSE[17112] logger.c: Peer audio RTP is at port 172.16.10.112:2236 Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Peer audio RTP is at port 172.16.10.112:2236 Jun 21 14:33:33 VERBOSE[17112] logger.c: Found description format PCMA Jun 21 14:33:33 VERBOSE[17112] logger.c: Found description format telephone-event Jun 21 14:33:33 VERBOSE[17112] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Jun 21 14:33:33 VERBOSE[17112] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: build_route: Contact hop: Jun 21 14:33:33 VERBOSE[17112] logger.c: list_route: hop: Jun 21 14:33:33 VERBOSE[17112] logger.c: set_destination: Parsing for address/port to send to Jun 21 14:33:33 VERBOSE[17112] logger.c: set_destination: set destination to 172.16.10.112, port 5060 Jun 21 14:33:33 VERBOSE[17112] logger.c: Transmitting (no NAT) to 172.16.10.112:5060: ACK sip:3053@172.16.10.112:5060 SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK19d9717e;rport From: "Ramal 3054" ;tag=as543f517a To: ;tag=42D3DD8F-325CCD70 Contact: Call-ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 14:33:33 VERBOSE[17144] logger.c: -- SIP/3053-89ad answered SIP/3054-bb66 Jun 21 14:33:33 DEBUG[17144] channel.c: Set channel SIP/3054-bb66 to read format alaw Jun 21 14:33:33 DEBUG[17144] channel.c: Set channel SIP/3053-89ad to write format alaw Jun 21 14:33:33 DEBUG[17144] channel.c: Set channel SIP/3053-89ad to read format alaw Jun 21 14:33:33 DEBUG[17144] channel.c: Set channel SIP/3054-bb66 to write format alaw Jun 21 14:33:33 DEBUG[17144] chan_sip.c: sip_answer(SIP/3054-bb66) Jun 21 14:33:33 VERBOSE[17144] logger.c: We're at 200.196.44.45 port 16392 Jun 21 14:33:33 VERBOSE[17144] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 14:33:33 VERBOSE[17144] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK23f9dd21ff3b5248;received=172.16.10.130 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as78451bbb Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3054 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 162 v=0 o=root 17078 17078 IN IP4 200.196.44.45 s=session c=IN IP4 200.196.44.45 t=0 0 m=audio 16392 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- Jun 21 14:33:33 DEBUG[17144] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #32 Jun 21 14:33:33 VERBOSE[17144] logger.c: -- Attempting native bridge of SIP/3054-bb66 and SIP/3053-89ad Jun 21 14:33:33 DEBUG[17095] chan_sip.c: Checking device state for peer 3053 Jun 21 14:33:33 DEBUG[17095] devicestate.c: Changing state for SIP/3053 - state 2 (In use) Jun 21 14:33:33 DEBUG[17095] chan_sip.c: Checking device state for peer 3054 Jun 21 14:33:33 DEBUG[17095] devicestate.c: Changing state for SIP/3054 - state 2 (In use) Jun 21 14:33:33 DEBUG[17147] app_queue.c: Device 'SIP/3053' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:33 DEBUG[17148] app_queue.c: Device 'SIP/3054' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:33 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: ACK sip:3053@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKa8f79a99dfa4bc46 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as78451bbb Contact: Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@200.196.44.45", nonce="6e09bc3c", response="c5876d0a10707359ba71dc1a35d08be4" Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3054 ACK User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 0: ACK sip:3053@200.196.44.45 SIP/2.0 (34) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKa8f79a99dfa4bc46 (61) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (95) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=as78451bbb (68) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 5: Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@200.196.44.45", nonce="6e09bc3c", response="c5876d0a10707359ba71dc1a35d08be4" (169) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 6: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 7: CSeq: 3054 ACK (14) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 8: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 9: Max-Forwards: 70 (16) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 10: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 11: Content-Length: 0 (17) Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Header 12: (0) Jun 21 14:33:33 VERBOSE[17112] logger.c: --- (12 headers 0 lines)Jun 21 14:33:33 VERBOSE[17112] logger.c: --- (12 headers 0 lines)--- Jun 21 14:33:33 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:33 DEBUG[17112] chan_sip.c: = Found Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:33 DEBUG[17112] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 14:33:33 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #32 Jun 21 14:33:33 DEBUG[17112] chan_sip.c: Stopping retransmission on 'e6ef9d214dd27545@172.16.10.130' of Response 3054: Match Found Jun 21 14:33:33 DEBUG[17144] rtp.c: Ooh, format changed from unknown to alaw Jun 21 14:33:33 DEBUG[17144] rtp.c: Ooh, format changed from unknown to alaw Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: INVITE sip:3053@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK26bcf95e17630f03 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as78451bbb Contact: Supported: replaces Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@200.196.44.45", nonce="6e09bc3c", response="6b34ca98805100eabced5ad3d9d80633" Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3055 INVITE User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Content-Length: 176 v=0 o=3054 8001 8002 IN IP4 172.16.10.130 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 10002 RTP/AVP 8 0 a=sendonly a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=ptime:20 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: INVITE sip:3053@200.196.44.45 SIP/2.0 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK26bcf95e17630f03 (61) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (95) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=as78451bbb (68) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: Supported: replaces (19) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@200.196.44.45", nonce="6e09bc3c", response="6b34ca98805100eabced5ad3d9d80633" (169) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: CSeq: 3055 INVITE (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 9: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 10: Max-Forwards: 70 (16) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 11: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 12: Content-Type: application/sdp (29) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 13: Content-Length: 176 (19) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 14: (0) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: v=0 (3) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: o=3054 8001 8002 IN IP4 172.16.10.130 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: s=SIP Call (10) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: c=IN IP4 0.0.0.0 (16) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: t=0 0 (5) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: m=audio 10002 RTP/AVP 8 0 (25) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: a=sendonly (10) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Line: a=ptime:20 (10) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (14 headers 10 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (14 headers 10 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:36 DEBUG[17112] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 21 14:33:36 VERBOSE[17112] logger.c: Using INVITE request as basis request - e6ef9d214dd27545@172.16.10.130 Jun 21 14:33:36 VERBOSE[17112] logger.c: Sending to 172.16.10.130 : 5060 (NAT) Jun 21 14:33:36 VERBOSE[17112] logger.c: Found RTP audio format 8 Jun 21 14:33:36 VERBOSE[17112] logger.c: Found RTP audio format 0 Jun 21 14:33:36 VERBOSE[17112] logger.c: Peer audio RTP is at port 0.0.0.0:10002 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Peer audio RTP is at port 0.0.0.0:10002 Jun 21 14:33:36 VERBOSE[17112] logger.c: Found description format PCMA Jun 21 14:33:36 VERBOSE[17112] logger.c: Found description format PCMU Jun 21 14:33:36 VERBOSE[17112] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Jun 21 14:33:36 VERBOSE[17112] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Jun 21 14:33:36 DEBUG[17112] channel.c: Set channel SIP/3053-89ad to write format slin Jun 21 14:33:36 VERBOSE[17112] logger.c: -- Started music on hold, class 'planetarium', on channel 'SIP/3053-89ad' Jun 21 14:33:36 DEBUG[17112] channel.c: Scheduling timer at 160 sample intervals Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Got a SIP re-invite for call e6ef9d214dd27545@172.16.10.130 Jun 21 14:33:36 VERBOSE[17112] logger.c: We're at 200.196.44.45 port 16392 Jun 21 14:33:36 VERBOSE[17112] logger.c: Adding codec 0x8 (alaw) to SDP Jun 21 14:33:36 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK26bcf95e17630f03;received=172.16.10.130 From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as78451bbb Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3055 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 162 v=0 o=root 17078 17079 IN IP4 200.196.44.45 s=session c=IN IP4 200.196.44.45 t=0 0 m=audio 16392 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - --- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #33 Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: REFER sip:3050@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK145fa5214dd5f96d From: ;tag=f4c05af8c7db954e To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 Contact: Supported: replaces Refer-To: Referred-By: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 11527 REFER User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: REFER sip:3050@200.196.44.45 SIP/2.0 (36) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK145fa5214dd5f96d (61) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: From: ;tag=f4c05af8c7db954e (62) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (78) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: Supported: replaces (19) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: Refer-To: (159) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: Referred-By: (62) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 9: CSeq: 11527 REFER (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 10: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 11: Max-Forwards: 70 (16) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 12: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 13: Content-Length: 0 (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 14: (0) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (14 headers 0 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (14 headers 0 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: **** Received REFER (9) - Command in SIP REFER Jun 21 14:33:36 DEBUG[17112] chan_sip.c: SIP call transfer received for call 358e288144c20d76777826511b917d82@200.196.44.45 (REFER)! Jun 21 14:33:36 VERBOSE[17112] logger.c: Transfer to 3053 in 3054_aux Jun 21 14:33:36 VERBOSE[17112] logger.c: Transfer from 3054 in 3054_aux Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Assigning Replace-Call-ID Info e6ef9d214dd27545@172.16.10.130 to REPLACE_CALL_ID Jun 21 14:33:36 DEBUG[17112] chan_sip.c: 202 Accepted (supervised) Jun 21 14:33:36 DEBUG[17112] chan_agent.c: Asked for bridged channel on 'SIP/3054-adae'/'Agent/3054', returning 'SIP/3050-e3c1' Jun 21 14:33:36 DEBUG[17112] channel.c: Set channel SIP/3050-e3c1 to write format alaw Jun 21 14:33:36 VERBOSE[17112] logger.c: -- Stopped music on hold on SIP/3050-e3c1 Jun 21 14:33:36 DEBUG[17112] channel.c: Scheduling timer at 0 sample intervals Jun 21 14:33:36 DEBUG[17112] channel.c: Set channel SIP/3053-89ad to write format alaw Jun 21 14:33:36 VERBOSE[17112] logger.c: -- Stopped music on hold on SIP/3053-89ad Jun 21 14:33:36 DEBUG[17112] channel.c: Scheduling timer at 0 sample intervals Jun 21 14:33:36 DEBUG[17112] chan_agent.c: Asked for bridged channel on 'SIP/3050-e3c1'/'Agent/3054', returning 'SIP/3054-adae' Jun 21 14:33:36 DEBUG[17112] channel.c: Planning to masquerade channel Agent/3054 into the structure of SIP/3054-bb66 Jun 21 14:33:36 DEBUG[17112] channel.c: Done planning to masquerade channel Agent/3054 into the structure of SIP/3054-bb66 Jun 21 14:33:36 VERBOSE[17112] logger.c: Transmitting (NAT) to 172.16.10.130:5060: SIP/2.0 202 Accepted Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bK145fa5214dd5f96d;received=172.16.10.130 From: ;tag=f4c05af8c7db954e To: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 11527 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 21 14:33:36 VERBOSE[17112] logger.c: set_destination: Parsing for address/port to send to Jun 21 14:33:36 DEBUG[17144] channel.c: Actually Masquerading Agent/3054(6) into the structure of SIP/3054-bb66(6) Jun 21 14:33:36 DEBUG[17144] channel.c: Got clone lock for masquerade on 'Agent/3054' at 0x9f26454 Jun 21 14:33:36 DEBUG[17144] chan_sip.c: Hangup call Agent/3054, SIP callid e6ef9d214dd27545@172.16.10.130) Jun 21 14:33:36 DEBUG[17144] chan_sip.c: update_call_counter(3054) - decrement call limit counter Jun 21 14:33:36 DEBUG[17144] chan_sip.c: Updating call counter for incoming call Jun 21 14:33:36 DEBUG[17144] channel.c: Set channel Agent/3054 to write format alaw Jun 21 14:33:36 DEBUG[17144] channel.c: Set channel Agent/3054 to read format alaw Jun 21 14:33:36 DEBUG[17144] channel.c: Putting channel Agent/3054 in 8/8 formats Jun 21 14:33:36 DEBUG[17144] channel.c: Released clone lock on 'SIP/3054-bb66' Jun 21 14:33:36 DEBUG[17144] channel.c: Done Masquerading Agent/3054 (6) Jun 21 14:33:36 DEBUG[17128] channel.c: Didn't get a frame from channel: SIP/3054-bb66 Jun 21 14:33:36 DEBUG[17128] channel.c: Bridge stops bridging channels SIP/3050-e3c1 and SIP/3054-bb66 Jun 21 14:33:36 DEBUG[17128] channel.c: Hanging up zombie 'SIP/3054-bb66' Jun 21 14:33:36 DEBUG[17128] pbx.c: Spawn extension (fila_desenvolvimento,3097,12) exited non-zero on 'SIP/3050-e3c1' Jun 21 14:33:36 DEBUG[17128] channel.c: Hanging up channel 'SIP/3050-e3c1' Jun 21 14:33:36 DEBUG[17128] chan_sip.c: Hangup call SIP/3050-e3c1, SIP callid XwwleZrXLRTRbZSJ@172.16.10.124) Jun 21 14:33:36 DEBUG[17128] chan_sip.c: update_call_counter(3050) - decrement call limit counter Jun 21 14:33:36 DEBUG[17128] chan_sip.c: Updating call counter for incoming call Jun 21 14:33:36 VERBOSE[17128] logger.c: set_destination: Parsing for address/port to send to Jun 21 14:33:36 VERBOSE[17128] logger.c: set_destination: set destination to 172.16.10.124, port 5060 Jun 21 14:33:36 VERBOSE[17128] logger.c: Reliably Transmitting (NAT) to 172.16.10.124:5060: BYE sip:3050@172.16.10.124:5060 SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK7f0a31d4;rport From: "3097" ;tag=as5fb71f40 To: "3050" ;tag=suzM66WNr09urc4w Contact: Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 14:33:36 DEBUG[17128] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #34 Jun 21 14:33:36 DEBUG[17128] res_monitor.c: monitor executing "/bin/nice -n 40 /usr/local/sbin/gc.registragravacao" "/var/spool/asterisk/monitor/1150911199.0-filadesenvolvimento-3097-in-20060621-143320-3050-in.WAV" "/var/spool/asterisk/monitor/1150911199.0-filadesenvolvimento-3097-in-20060621-143320-3050-out.WAV" "/var/spool/asterisk/monitor/1150911199.0-filadesenvolvimento-3097-in-20060621-143320-3050.WAV" & Jun 21 14:33:36 VERBOSE[17112] logger.c: set_destination: set destination to 172.16.10.130, port 5060 Jun 21 14:33:36 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: NOTIFY sip:3054@172.16.10.130;user=phone SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK23947e0c;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Contact: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 103 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=11527 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Content-Length: 14 SIP/2.0 200 OK --- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 Jun 21 14:33:36 VERBOSE[17112] logger.c: set_destination: Parsing for address/port to send to Jun 21 14:33:36 VERBOSE[17112] logger.c: set_destination: set destination to 172.16.10.130, port 5060 Jun 21 14:33:36 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: BYE sip:3054@172.16.10.130;user=phone SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK089fe834;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Contact: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #36 Jun 21 14:33:36 DEBUG[17095] chan_sip.c: Checking device state for peer 3054 Jun 21 14:33:36 DEBUG[17095] devicestate.c: Changing state for SIP/3054 - state 2 (In use) Jun 21 14:33:36 DEBUG[17095] chan_sip.c: Checking device state for peer 3050 Jun 21 14:33:36 DEBUG[17095] devicestate.c: Changing state for SIP/3050 - state 1 (Not in use) Jun 21 14:33:36 DEBUG[17151] app_queue.c: Device 'SIP/3054' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 21 14:33:36 DEBUG[17152] app_queue.c: Device 'SIP/3050' changed to state '1' (Not in use) Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: ACK sip:3053@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf4f7710c863915bd From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 To: ;tag=as78451bbb Contact: Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@200.196.44.45", nonce="6e09bc3c", response="c5876d0a10707359ba71dc1a35d08be4" Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 3055 ACK User-Agent: Grandstream BT100 1.0.6.7 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: ACK sip:3053@200.196.44.45 SIP/2.0 (34) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.16.10.130;branch=z9hG4bKf4f7710c863915bd (61) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: From: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (95) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=as78451bbb (68) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: Contact: (44) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: Proxy-Authorization: Digest username="3054", realm="asterisk", algorithm=MD5, uri="sip:3053@200.196.44.45", nonce="6e09bc3c", response="c5876d0a10707359ba71dc1a35d08be4" (169) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: CSeq: 3055 ACK (14) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 9: Max-Forwards: 70 (16) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 10: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 11: Content-Length: 0 (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 12: (0) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (12 headers 0 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (12 headers 0 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:36 DEBUG[17112] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 21 14:33:36 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #33 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Stopping retransmission on 'e6ef9d214dd27545@172.16.10.130' of Response 3055: Match Found Jun 21 14:33:36 VERBOSE[17112] logger.c: set_destination: Parsing for address/port to send to Jun 21 14:33:36 VERBOSE[17112] logger.c: set_destination: set destination to 172.16.10.130, port 5060 Jun 21 14:33:36 VERBOSE[17112] logger.c: Reliably Transmitting (NAT) to 172.16.10.130:5060: CANCEL :3053@200.196.44.45 SIP/2.0 Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK45fe168e;rport From: ;tag=as78451bbb To: "Ramal Teste 3054" ;tag=a83d42d4b3386785 Contact: Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 101 CANCEL User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 Jun 21 14:33:36 VERBOSE[17112] logger.c: Scheduling destruction of call 'e6ef9d214dd27545@172.16.10.130' in 32000 ms Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK23947e0c;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 103 NOTIFY User-Agent: Grandstream BT100 1.0.6.7 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Supported: replaces Content-Length: 0 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK23947e0c;rport (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (80) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=f4c05af8c7db954e (60) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: CSeq: 103 NOTIFY (16) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: Contact: (44) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 9: Supported: replaces (19) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (11 headers 0 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (11 headers 0 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Stopping retransmission on '358e288144c20d76777826511b917d82@200.196.44.45' of Request 103: Match Found Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK089fe834;rport From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 To: ;tag=f4c05af8c7db954e Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 CSeq: 104 BYE User-Agent: Grandstream BT100 1.0.6.7 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Supported: replaces Content-Length: 0 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK089fe834;rport (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: From: "Fila:desenvolvimento:Ramal Teste" ;tag=as7fd943f4 (80) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: To: ;tag=f4c05af8c7db954e (60) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: Call-ID: 358e288144c20d76777826511b917d82@200.196.44.45 (55) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: CSeq: 104 BYE (13) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: Contact: (44) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 9: Supported: replaces (19) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (11 headers 0 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (11 headers 0 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #36 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Stopping retransmission on '358e288144c20d76777826511b917d82@200.196.44.45' of Request 104: Match Found Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK45fe168e;rport From: ;tag=as78451bbb To: "Ramal Teste 3054" ;tag=a83d42d4b3386785 Call-ID: e6ef9d214dd27545@172.16.10.130 CSeq: 101 CANCEL User-Agent: Grandstream BT100 1.0.6.7 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Supported: replaces Content-Length: 0 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK45fe168e;rport (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: From: ;tag=as78451bbb (70) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: To: "Ramal Teste 3054" ;tag=a83d42d4b3386785 (93) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: Call-ID: e6ef9d214dd27545@172.16.10.130 (39) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: CSeq: 101 CANCEL (16) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: User-Agent: Grandstream BT100 1.0.6.7 (37) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: Contact: (44) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 9: Supported: replaces (19) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 11: (0) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (11 headers 0 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (11 headers 0 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: e6ef9d214dd27545@172.16.10.130 Their Tag a83d42d4b3386785 Our tag: as78451bbb Jun 21 14:33:36 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Stopping retransmission on 'e6ef9d214dd27545@172.16.10.130' of Request 101: Match Found Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Got 200 OK on CANCEL Jun 21 14:33:36 VERBOSE[17112] logger.c: Destroying call 'e6ef9d214dd27545@172.16.10.130' Jun 21 14:33:36 VERBOSE[17112] logger.c: <-- SIP read from 172.16.10.124:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK7f0a31d4;rport Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 CSeq: 102 BYE From: "3097" ;tag=as5fb71f40 To: "3050" ;tag=suzM66WNr09urc4w Contact: Content-Length: 0 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 1: Via: SIP/2.0/UDP 200.196.44.45:5060;branch=z9hG4bK7f0a31d4;rport (64) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 2: Call-ID: XwwleZrXLRTRbZSJ@172.16.10.124 (39) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 3: CSeq: 102 BYE (13) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 4: From: "3097" ;tag=as5fb71f40 (66) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 5: To: "3050" ;tag=suzM66WNr09urc4w (70) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 6: Contact: (38) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 7: Content-Length: 0 (17) Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Header 8: (0) Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (8 headers 0 lines)Jun 21 14:33:36 VERBOSE[17112] logger.c: --- (8 headers 0 lines)--- Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 66137c0836bdbc261d4fd80359ebf035@200.196.44.45 Their Tag 42D3DD8F-325CCD70 Our tag: as543f517a Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = No match Their Call ID: 358e288144c20d76777826511b917d82@200.196.44.45 Their Tag f4c05af8c7db954e Our tag: as7fd943f4 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: = Found Their Call ID: XwwleZrXLRTRbZSJ@172.16.10.124 Their Tag suzM66WNr09urc4w Our tag: as5fb71f40 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #34 Jun 21 14:33:36 DEBUG[17112] chan_sip.c: Stopping retransmission on 'XwwleZrXLRTRbZSJ@172.16.10.124' of Request 102: Match Found Jun 21 14:33:36 VERBOSE[17112] logger.c: Destroying call 'XwwleZrXLRTRbZSJ@172.16.10.124' Jun 21 14:33:40 DEBUG[17144] rtp.c: Got RTCP report of 136 bytes Jun 21 14:33:41 DEBUG[17101] chan_iax2.c: Allocate call number Jun 21 14:33:41 DEBUG[17101] chan_iax2.c: Registration created on call 7 Jun 21 14:33:42 DEBUG[17109] chan_agent.c: Asked for bridged channel on 'SIP/3053-89ad'/'Agent/3054', returning 'SIP/3054-adae' pfdesenv*CLI> show channels Channel Location State Application(Data) SIP/3053-89ad (None) Up Bridged Call(Agent/3054) Agent/3054 s@macro-atende:900 Up Dial(SIP/3053|30|tT) pfdesenv*CLI> Disconnected from Asterisk server Executing last minute cleanups