| Summary: | ASTERISK-17146: [patch] Problem with dialing SIP peer that is not reachable. | ||||||||||||
| Reporter: | Jarek Jarzebowski (jarekj) | Labels: | |||||||||||
| Date Opened: | 2010-12-21 15:32:50.000-0600 | Date Closed: | 2011-10-18 18:45:41 | ||||||||||
| Priority: | Minor | Regression? | Yes | ||||||||||
| Status: | Closed/Complete | Components: | Channels/chan_sip/General | ||||||||||
| Versions: | Frequency of Occurrence | ||||||||||||
| Related Issues: |
| ||||||||||||
| Environment: | Attachments: | ( 0) ast_check_digits.patch.txt ( 1) full_non_exist_peer.txt ( 2) full.log ( 3) full.tgz ( 4) invalid_lookups.patch.txt ( 5) issue18514.patch ( 6) issue18514.patch.v2 ( 7) issue18514.patch.v3 ( 8) netsocks_log_patch_v2.txt ( 9) sip_debug_non_exist_peer.txt (10) sip_debug_on_patch_v2.txt (11) sip.conf (12) sip.conf.tgz | |||||||||||
| Description: | I am using: *CLI> core show version Asterisk 1.8.1.1 built by root @ asterisk on a i686 running Linux on 2010-12-17 23:03:58 UTC I have some problem with DIal() to SIP unreachable friend. My dialplan: exten => _XXXX,1,Dial(SIP/${EXTEN},60,rt) Now, when I Dial extension 1050, and there is no 1050 peer registered I got: [Dec 18 22:51:04] WARNING[2307] chan_sip.c: sip_xmit of 0xc2e1330 (len 843) to 0.0.4.26:5060 returned -1: Invalid argument | ||||||||||||
| Comments: | By: Paul Belanger (pabelanger) 2010-12-21 17:47:19.000-0600 Please re-upload your attachments, no need to compress them. By: Jarek Jarzebowski (jarekj) 2010-12-22 00:09:58.000-0600 Attachments re-uploaded, uncompressed. By: Chodorenko Michail (chodorenko) 2010-12-29 14:25:53.000-0600 Yes its true bug, on my system i view it By: Satish Patel (satish_lx) 2011-04-08 14:13:18 I am also look for solution for this. I have tried this behavior with various version 1.2, 1.4, 1.6 but only issue found with asterisk-1.8.x look like they did some changes in chan_sip.c which is waiting for ACK of unreachable SIP peer :( By: Satish Patel (satish_lx) 2011-04-11 12:43:22 @Imadsen - If you need any logs i can provide you in order to fix this issue. even i have attached them here https://issues.asterisk.org/view.php?id=19087 By: Satish Patel (satish_lx) 2011-04-18 10:02:36 Any update ? Still i am waiting to fix this bug :( By: Satish Patel (satish_lx) 2011-04-26 13:14:30 Admin, Any luck to review this issue ? If this will take time then please let me know i go back to 1.4.x or 1.6.x version. Appreciate your kind help. By: Paul Belanger (pabelanger) 2011-04-28 13:30:07 Yes, this looks to be an issue, but also a configuration issue. SIP peer 1050 does not exists in sip.conf. So, asterisk does not know how to dial it. Edit: Checking to see how 1.4 handled this. By: Satish Patel (satish_lx) 2011-04-28 13:39:41 I have checked with 1.2, 1.4, 1.6 all are working great without any issue. When peer is not available then it should say something like host unreachable or peer why it's waiting for timeout. also i am every time getting wired revers ip i don't know from where its coming i don't have this kind of any ip in my company even. See full debug here https://issues.asterisk.org/view.php?id=19087 I have attached bunch of files. By: Bryant Zimmerman (zktech) 2011-04-28 13:48:44 I have seen this as well. I have had to go to doing very explicite checking of every peer before allowing issuing the dial. If I don't and the peer is off line the Dial comand holds up the dial plan for multiple seconds and the caller sucks dead air. This is a bug from my perspective. By: Terry Wilson (twilson) 2011-04-28 14:19:44 I believe this is also what I am seeing with 19144. Even if Asterisk fails to lookup a host via DNS, it tries to send it an INVITE. It may be doing the same thing for non existent peers as well. I just tested this on my machine. In my case, it looks like it may be related to my damn ISP (Time Warner Cable) playing DNS games and handling back 208.68.139.89 (their stupid advertisement search page) when a DNS lookup fails. So we then start sending INVITES to their f#$%ing web server. By: Satish Patel (satish_lx) 2011-04-28 14:21:18 You know i have hack this in code and fix issue but i don't what to do that. i would like to maintain this by community. what i did is following. in chan_sip.c file /* Do not retransmit if time out is reached. This will be negative if the time between * the first transmission and now is larger than our timeout period. This is a fail safe * check in case the scheduler gets behind or the clock is changed. */ if ((diff <= 0) || (diff > pkt->retrans_stop_time)) { pkt->retrans_stop = 1; } I have changed ((diff <= 0) || (diff > pkt->retrans_stop_time)) { to ((diff != 0) || (diff > pkt->retrans_stop_time)) { And it fixed my issue now its not waiting for timeout and re-transmit packet on dead unavailable peer. But i would like if asterisk community sign off and say this is good to go. By: Paul Belanger (pabelanger) 2011-04-28 14:39:56 Give this a try. By: Satish Patel (satish_lx) 2011-04-28 14:47:50 I tired your patch and no luck :( -- Executing [7203@from-sip:1] Macro("SIP/7207-00000004", "stdexten,7203,sip/7203") in new stack -- Executing [s@macro-stdexten:1] Dial("SIP/7207-00000004", "sip/7203,10,t") in new stack == Using SIP RTP CoS mark 5 [Apr 28 15:47:05] WARNING[7789]: acl.c:698 ast_ouraddrfor: Cannot connect [Apr 28 15:47:05] WARNING[7789]: chan_sip.c:3240 __sip_xmit: sip_xmit of 0x19db1f0 (len 764) to 0.0.28.35:5060 returned -1: Invalid argument -- Called 7203 [Apr 28 15:47:05] WARNING[7741]: chan_sip.c:3240 __sip_xmit: sip_xmit of 0x19db1f0 (len 764) to 0.0.28.35:5060 returned -1: Invalid argument [Apr 28 15:47:06] WARNING[7741]: chan_sip.c:3240 __sip_xmit: sip_xmit of 0x19bed20 (len 762) to 0.0.28.35:5060 returned -1: Invalid argument [Apr 28 15:47:06] WARNING[7741]: chan_sip.c:3240 __sip_xmit: sip_xmit of 0x19db1f0 (len 764) to 0.0.28.35:5060 returned -1: Invalid argument [Apr 28 15:47:08] WARNING[7741]: chan_sip.c:3240 __sip_xmit: sip_xmit of 0x19db1f0 (len 764) to 0.0.28.35:5060 returned -1: Invalid argument [Apr 28 15:47:12] WARNING[7741]: chan_sip.c:3240 __sip_xmit: sip_xmit of 0x19db1f0 (len 764) to 0.0.28.35:5060 returned -1: Invalid argument -- Nobody picked up in 10000 ms By: Paul Belanger (pabelanger) 2011-04-28 15:02:34 Upload a debug log with the patch if you don't mind, be sure to enable sip debugs. Does sip/7203 exist? Edit: nevermind, I see my issue. By: Satish Patel (satish_lx) 2011-04-28 15:09:51 @pabelanger I have upload sip_debug_non_exist_peer.txt file. No SIP/7203 not exist By: Satish Patel (satish_lx) 2011-04-28 15:16:17 @pabelanger I have uploaded one more /var/log/asterisk/full file. By: Satish Patel (satish_lx) 2011-04-28 15:56:11 @pabelanger Did you find something ? let me know i will test it. By: Paul Belanger (pabelanger) 2011-04-28 16:49:58 Version 2: This should fix it, however I'll need review if this is the proper way to do so. By: Satish Patel (satish_lx) 2011-04-28 18:39:42 Look like it solved 50% issue i meant no error related revers IP and _sip_xmit warning but still its waiting for few second before say invalid extension. also i found new errors related netsocks i have uploaded log files. By: Paul Belanger (pabelanger) 2011-04-28 18:51:52 Are you able to get on #asterisk-bugs, will be easier to communicate. By: Paul Belanger (pabelanger) 2011-04-28 19:23:05 Version 3: Better description of the error. By: Satish Patel (satish_lx) 2011-04-28 19:42:31 >Are you able to get on #asterisk-bugs, will be easier to communicate. I have never used it. I would like to know and how to use it. could you point me there? >Version 3: >Better description of the error. Right now i am at home so i will give it a shot tomorrow and get back to you. I hope tomorrow we will get this resolved. because i have schedule my production migration on next week Sunday. Thanks for your great support. By: Satish Patel (satish_lx) 2011-04-29 09:12:25 @pabelanger, Much much better v3 is. There is a 5 second silence before it say Invalid extension :) But in asterisk 1.2 and 1.4 has only 1 or 2 second to declare invalid extension. Now i am getting following error "ERROR[12988]" RED keyword sometime looks scary to me :( can we change it to WARNING :) [Apr 29 10:08:44] ERROR[12988]: netsock2.c:263 ast_sockaddr_resolve: Unable to resolve hostname '7203': Name or service not known [Apr 29 10:08:44] WARNING[12988]: chan_sip.c:5182 create_addr: No such host: 7203 [Apr 29 10:08:44] WARNING[12988]: app_dial.c:2039 dial_exec_full: Unable to create channel of type 'sip' (cause 20 - Unknown) By: Paul Belanger (pabelanger) 2011-04-29 11:22:09 Well, its actually an error, since it cannot resolve the DNS for 7203. By: Satish Patel (satish_lx) 2011-04-29 11:45:01 Okay! That is fine. So can i put this code in production ? or do you need any review ? Also, can we make 5 second dead air sound to 1 or 2 second ? Just wondering if possible. By: Paul Belanger (pabelanger) 2011-04-29 12:00:02 This is outside the control of Asterisk, it is your DNS server timeout. Yes, I need to get this code reviewed. By: Satish Patel (satish_lx) 2011-04-29 12:02:22 Thanks, Let me know when you done with review so i go ahead and put this in production. I have only one week to take decision :( By: Paul Belanger (pabelanger) 2011-04-29 12:10:26 promoted to 'Ready for Review' By: Satish Patel (satish_lx) 2011-05-18 15:40:09 When will review complete ? By: Ronald Chan (loloski) 2011-05-23 06:45:33 i'm blauntly say this, i'm fine with the patch attach to this issue, AFAIC it works as expected, satish_lx the patch was running in production for almost 3 weeks. no i'll effects so far. By: Satish Patel (satish_lx) 2011-05-23 07:20:24 Thanks for your review loloski. @ Asterisk dev please consider it and add it to SVN or trunk so we can see more test results. I'm going to add this patch in production. By: Satish Patel (satish_lx) 2011-05-23 07:20:32 Thanks for your review loloski. @ Asterisk dev please consider it and add it to SVN or trunk so we can see more test results. I'm going to add this patch in production. By: ornix (ornix) 2011-06-01 02:03:47 patch.v3 doesn't resolve this issue in my case. With this patch i can't do calls at all. I'll upload log-files today. By: Jeremy Kister (jkister) 2011-06-15 01:07:46.553-0500 patch v3 is evil. I applied patch v3 to asterisk 1.8.4.2 When I try to make a call, i see on the console: {code} pbx1*CLI> == Using UDPTL CoS mark 5 [Jun 15 02:04:30] ERROR[18464]: netsock2.c:263 ast_sockaddr_resolve: Unable to resolve hostname '10.0.1.111': Name or service not known [Jun 15 02:04:30] ERROR[18464]: netsock2.c:263 ast_sockaddr_resolve: Unable to resolve hostname '10.0.1.111': Name or service not known == Using SIP RTP CoS mark 5 [Jun 15 02:04:30] ERROR[18464]: netsock2.c:263 ast_sockaddr_resolve: Unable to resolve hostname '10.0.1.111': Name or service not known [Jun 15 02:04:30] WARNING[18464]: chan_sip.c:8989 process_sdp_c: Unable to lookup RTP Audio host in c= line, 'IN IP4 10.0.1.111' [Jun 15 02:04:30] WARNING[18464]: chan_sip.c:8630 process_sdp: Insufficient information in SDP (c=)... {code} I then get fast busy. this might have to do with the DNS service providing NXDOMAN on RFC1918 address space why are we involving DNS on a call when the destination is an IP Address anyway ? that'd make asterisk break if/when DNS is unavailable. By: Matej Ondrusek (matejcx) 2011-06-26 05:36:53.751-0500 I think the big question here is if it is OK, that Asterisk tries to interpret Dial(SIP/devicename) syntax as a Dial(SIP/hostname)syntax when it is not able to find devicename in the list of peers. In my opinion this behavior is wrong, there should be a clear way how to distinguish this two cases by different syntax so Dial(SIP/devicename) should in no case result in interpreting "devicename" as a "hostname" or even as a "IP address", if it is numeric. In my opinion the severity of this bug should be raised, since it can possibly be also security problem. If somebody has "exten => _.,1,Dial(SIP/${EXTEN})" line in dial plan, it will allow to call any host/ip. By: Terry Wilson (twilson) 2011-10-18 14:32:14.199-0500 Please try the invalid_lookups.patch.txt. Things like '1050' are technically valid representations of IP addresses (0.0.4.26 in the case of 1050). This patch rejects any purely numeric hostnames when we don't find a peer with that name. It also should fix another issue where we would try to send a request to destination when we couldn't resolve its address. By: Terry Wilson (twilson) 2011-10-18 18:45:41.589-0500 Fixed in 1.8+ By: Jeremy Kister (jkister) 2011-10-18 22:35:57.612-0500 Sorry, what do you mean 'Fixed in 1.8+' ? 1.8.8 + ? it's certainly broken in several versions of 1.8, including 1.8.4 and 1.8.7 or are you saying that it's fixed in 1.8+ with your patch? By: Terry Wilson (twilson) 2011-10-19 00:39:18.344-0500 No, fixed in the branches 1.8, 10, and trunk from this point forward. By: Jeremy Kister (jkister) 2011-10-19 01:30:49.755-0500 oh, i get it. i tested out the patch, works great on debian, but it fails on Solaris 10 s1*CLI> module load chan_sip.so Unable to load module chan_sip.so Command 'module load chan_sip.so ' failed. [Oct 19 02:28:04] WARNING[15759]: loader.c:449 load_dynamic_module: Error loading module 'chan_sip.so': ld.so.1: asterisk: fatal: relocation error: file /usr/local/lib/asterisk/modules/chan_sip.so: symbol is_int: referenced symbol not found [Oct 19 02:28:04] WARNING[15759]: loader.c:839 load_resource: Module 'chan_sip.so' could not be loaded. By: Terry Wilson (twilson) 2011-10-19 02:12:15.597-0500 Hmm, I suppose I could make a copy of the is_int() code from the pval stuff to strings.h using the AST_INLINE_API. Someone had similar code in a patch they put up on reviewboard for a completely unrelated issue. By: Terry Wilson (twilson) 2011-10-19 02:25:06.609-0500 Try this on your solaris box (in addition to the other patch, as this is diffed from the branch). By: Terry Wilson (twilson) 2011-10-19 02:30:52.009-0500 With this = ast_check_digits.patch.txt By: Jeremy Kister (jkister) 2011-10-19 03:18:03.771-0500 yep, now all is happy. i read your post regarding sipconnect on asterisk-dev and thought i should mention that i don't have ael modules loaded on my solaris box; that might actually be the culprit of the missing is_int() rather than the OS itself. By: mts-tel (mts-tel) 2011-10-19 04:27:56.524-0500 $ cat /proc/version Linux version 2.6.32-5-amd64 (Debian 2.6.32-35) (dannf@debian.org) (gcc version 4.3.5 (Debian 4.3.5-4) ) #1 SMP Tue Jun 14 09:42:28 UTC 2011 $ asterisk -rvvvvdddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddddd buhphone*CLI> core show version Asterisk 1.8.7.1 built by root @ buhphone on a x86_64 running Linux on 2011-10-19 07:28:35 UTC buhphone*CLI> dialplan show from-trunk-custom [ Context 'from-trunk-custom' created by 'pbx_config' ] '8888' => 1. Goto(from-internal,${EXTEN},1) [pbx_config] '9999' => 1. Goto(echo,s,1) [pbx_config] '_[01]XXXXXX' => 1. Macro(diall,SIP/${EXTEN},120,T) [pbx_config] '_XXXXXX' => 1. Macro(diall,SIP/${EXTEN},120,T) [pbx_config] '_XXX' => 1. Goto(from-internal,${EXTEN},1) [pbx_config] -= 5 extensions (5 priorities) in 1 context. =- buhphone*CLI> dialplan show macro-diall [ Context 'macro-diall' created by 'pbx_config' ] 's' => 1. NoOp(Callerid: ${CALLERID(number)}) [pbx_config] 2. ChanIsAvail(${ARG1}) [pbx_config] 3. NoOp(${AVAILORIGCHAN}) [pbx_config] 4. GotoIf($[${LEN(a${AVAILORIGCHAN})} < 3]?busy) [pbx_config] 5. Dial(${ARG1},${ARG2},${ARG3}) [pbx_config] [busy] 6. NoOp(Busy) [pbx_config] 7. Hangup() [pbx_config] -= 1 extension (7 priorities) in 1 context. =- buhphone*CLI> [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:7835 find_call: = Looking for Call ID: 1852407599@188.XXX.XXX.38 (Checking From) --From tag 1663240149 --To-tag [2011-10-19 13:24:16] DEBUG[18853]: acl.c:725 ast_ouraddrfor: For destination '91.XXX.XXX.244', our source address is '188.XXX.XXX.38'. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 188.XXX.XXX.38:5060 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for 1852407599@188.XXX.XXX.38 - INVITE (No RTP) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:24471 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '91.XXX.XXX.244:7237' into... [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '91.XXX.XXX.244' and port '7237'. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:3325 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 91.XXX.XXX.244:7237 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:7835 find_call: = Looking for Call ID: 1852407599@188.XXX.XXX.38 (Checking From) --From tag 1663240149 --To-tag as76c2a225 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:24471 handle_incoming: **** Received ACK (6) - Command in SIP ACK [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:4011 __sip_ack: Stopping retransmission on '1852407599@188.XXX.XXX.38' of Response 81: Match Found [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:7835 find_call: = Looking for Call ID: 1852407599@188.XXX.XXX.38 (Checking From) --From tag 1663240149 --To-tag [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '188.XXX.XXX.38' into... [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '188.XXX.XXX.38' and port ''. [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '188.XXX.XXX.38' into... [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '188.XXX.XXX.38' and port ''. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:24471 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '91.XXX.XXX.244:7237' into... [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '91.XXX.XXX.244' and port '7237'. [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:345 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f77880067c8' [2011-10-19 13:24:16] DEBUG[18853]: res_rtp_asterisk.c:483 ast_rtp_new: Allocated port 19494 for RTP instance '0x7f77880067c8' [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:354 ast_rtp_instance_new: RTP instance '0x7f77880067c8' is setup and ready to go [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:345 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f778803a7c8' [2011-10-19 13:24:16] DEBUG[18853]: res_rtp_asterisk.c:483 ast_rtp_new: Allocated port 11756 for RTP instance '0x7f778803a7c8' [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:354 ast_rtp_instance_new: RTP instance '0x7f778803a7c8' is setup and ready to go [2011-10-19 13:24:16] DEBUG[18853]: res_rtp_asterisk.c:2394 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f778803a7c8' [2011-10-19 13:24:16] DEBUG[18853]: res_rtp_asterisk.c:2394 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f77880067c8' == Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:4934 do_setnat: Setting NAT on RTP to On [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:4938 do_setnat: Setting NAT on VRTP to On [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8626 process_sdp: Processing session-level SDP v=0... UNSUPPORTED. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8626 process_sdp: Processing session-level SDP o=yate 1319016256 1319016256 IN IP4 91.XXX.XXX.244... UNSUPPORTED. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8626 process_sdp: Processing session-level SDP s=SIP Call... UNSUPPORTED. [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '91.XXX.XXX.244' into... [2011-10-19 13:24:16] DEBUG[18853]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '91.XXX.XXX.244' and port ''. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8626 process_sdp: Processing session-level SDP c=IN IP4 91.XXX.XXX.244... OK. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8626 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED. [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:536 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:536 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:536 ast_rtp_codecs_payloads_set_m_type: Setting payload 3 based on m type on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:536 ast_rtp_codecs_payloads_set_m_type: Setting payload 11 based on m type on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:536 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8813 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8813 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8813 process_sdp: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8813 process_sdp: Processing media-level (audio) SDP a=rtpmap:11 L16/8000... OK. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:8813 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:639 ast_rtp_codecs_payload_formats: Incorporating payload 0 on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:639 ast_rtp_codecs_payload_formats: Incorporating payload 3 on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:639 ast_rtp_codecs_payload_formats: Incorporating payload 8 on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:639 ast_rtp_codecs_payload_formats: Incorporating payload 11 on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:639 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0x7f778d3b31d0 [2011-10-19 13:24:16] DEBUG[18853]: res_rtp_asterisk.c:2415 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f77880067c8' [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:517 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0x7f778d3b31d0 to 0x7f7788006990 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:517 ast_rtp_codecs_payloads_copy: Copying payload 3 from 0x7f778d3b31d0 to 0x7f7788006990 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:517 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0x7f778d3b31d0 to 0x7f7788006990 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:517 ast_rtp_codecs_payloads_copy: Copying payload 11 from 0x7f778d3b31d0 to 0x7f7788006990 [2011-10-19 13:24:16] DEBUG[18853]: rtp_engine.c:517 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7f778d3b31d0 to 0x7f7788006990 [2011-10-19 13:24:16] DEBUG[18853]: res_rtp_asterisk.c:2415 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f778803a7c8' [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:9046 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:22043 handle_request_invite: Checking SIP call limits for device 315166 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:5750 update_call_counter: Updating call counter for incoming call [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 315166 [2011-10-19 13:24:16] DEBUG[18845]: chan_sip.c:25695 sip_devicestate: Checking device state for peer 315166 [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:458 do_state_change: Changing state for SIP/315166 - state 2 (In use) [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:438 devstate_event: device 'SIP/315166' state '2' [2011-10-19 13:24:16] DEBUG[18880]: app_queue.c:1491 handle_statechange: Device 'SIP/315166' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:6845 sip_new: *** Our native formats are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:6846 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:6847 sip_new: *** Our capabilities are 0x38000e (gsm|ulaw|alaw|h263|h263p|h264) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:6848 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:6876 sip_new: This channel can handle video! HOLLYWOOD next! [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:13763 build_route: build_route: Contact hop: <sip:315166@91.XXX.XXX.244:7237> [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:22335 handle_request_invite: SIP/315166-0000002b: New call is still down.... Trying... [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:3325 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 91.XXX.XXX.244:7237 [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 315166 [2011-10-19 13:24:16] DEBUG[18845]: chan_sip.c:25695 sip_devicestate: Checking device state for peer 315166 [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:458 do_state_change: Changing state for SIP/315166 - state 2 (In use) [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:438 devstate_event: device 'SIP/315166' state '2' [2011-10-19 13:24:16] DEBUG[18880]: app_queue.c:1491 handle_statechange: Device 'SIP/315166' changed to state '2' (In use) but we don't care because they're not a member of any queue. [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'EXTEN' is '542124' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:4100 pbx_extension_helper: Launching 'Macro' -- Executing [542124@from-trunk:1] Macro("SIP/315166-0000002b", "diall,SIP/542124,120,T") in new stack [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3928 pbx_substitute_variables_helper_full: Function result is '315166' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:4100 pbx_extension_helper: Launching 'NoOp' -- Executing [s@macro-diall:1] NoOp("SIP/315166-0000002b", "Callerid: 315166") in new stack [2011-10-19 13:24:16] DEBUG[19107]: app_macro.c:435 _macro_exec: Executed application: NoOp [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'ARG1' is 'SIP/542124' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:4100 pbx_extension_helper: Launching 'ChanIsAvail' -- Executing [s@macro-diall:2] ChanIsAvail("SIP/315166-0000002b", "SIP/542124") in new stack [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:25797 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for 0748ca24728af5c7670bc4a40413bcde@127.0.1.1:0 - INVITE (No RTP) [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:345 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x22a9b78' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:483 ast_rtp_new: Allocated port 12870 for RTP instance '0x22a9b78' [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:354 ast_rtp_instance_new: RTP instance '0x22a9b78' is setup and ready to go [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:345 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x22befd8' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:483 ast_rtp_new: Allocated port 14440 for RTP instance '0x22befd8' [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:354 ast_rtp_instance_new: RTP instance '0x22befd8' is setup and ready to go [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:2394 ast_rtp_prop_set: Setup RTCP on RTP instance '0x22befd8' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:2394 ast_rtp_prop_set: Setup RTCP on RTP instance '0x22a9b78' == Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:4934 do_setnat: Setting NAT on RTP to Off [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:4938 do_setnat: Setting NAT on VRTP to Off [2011-10-19 13:24:16] DEBUG[19107]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '542124' into... [2011-10-19 13:24:16] DEBUG[19107]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '542124' and port ''. [2011-10-19 13:24:16] WARNING[19107]: acl.c:708 ast_ouraddrfor: Cannot connect [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 127.0.1.1:5060 [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6845 sip_new: *** Our native formats are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6846 sip_new: *** Joint capabilities are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6847 sip_new: *** Our capabilities are 0x38000e (gsm|ulaw|alaw|h263|h263p|h264) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6848 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6850 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6876 sip_new: This channel can handle video! HOLLYWOOD next! [2011-10-19 13:24:16] DEBUG[19107]: channel.c:2819 ast_hangup: Hanging up channel 'SIP/542124-0000002c' [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6121 sip_hangup: Hanging up zombie call. Be scared. [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6142 sip_hangup: Hanging up channel in state Down (not UP) [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:2415 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x22a9b78' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:2415 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x22befd8' [2011-10-19 13:24:16] DEBUG[19107]: app_macro.c:435 _macro_exec: Executed application: ChanIsAvail [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 542124 [2011-10-19 13:24:16] DEBUG[18845]: chan_sip.c:25695 sip_devicestate: Checking device state for peer 542124 [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'AVAILORIGCHAN' is 'SIP/542124' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:4100 pbx_extension_helper: Launching 'NoOp' -- Executing [s@macro-diall:3] NoOp("SIP/315166-0000002b", "SIP/542124") in new stack [2011-10-19 13:24:16] DEBUG[19107]: app_macro.c:435 _macro_exec: Executed application: NoOp [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:458 do_state_change: Changing state for SIP/542124 - state 0 (Unknown) [2011-10-19 13:24:16] DEBUG[18845]: devicestate.c:438 devstate_event: device 'SIP/542124' state '0' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'AVAILORIGCHAN' is 'SIP/542124' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3928 pbx_substitute_variables_helper_full: Function result is '11' [2011-10-19 13:24:16] DEBUG[18880]: app_queue.c:1491 handle_statechange: Device 'SIP/542124' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3996 pbx_substitute_variables_helper_full: Expression result is '0' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:4100 pbx_extension_helper: Launching 'GotoIf' -- Executing [s@macro-diall:4] GotoIf("SIP/315166-0000002b", "0?busy") in new stack [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:9949 pbx_builtin_gotoif: Not taking any branch [2011-10-19 13:24:16] DEBUG[19107]: app_macro.c:435 _macro_exec: Executed application: GotoIf [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'ARG1' is 'SIP/542124' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'ARG2' is '120' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:3109 ast_str_retrieve_variable: Result of 'ARG3' is 'T' [2011-10-19 13:24:16] DEBUG[19107]: pbx.c:4100 pbx_extension_helper: Launching 'Dial' -- Executing [s@macro-diall:5] Dial("SIP/315166-0000002b", "SIP/542124,120,T") in new stack [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:25797 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for 49f383e574506a2367417ee33bb38503@127.0.1.1:0 - INVITE (No RTP) [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:345 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f77a42606f8' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:483 ast_rtp_new: Allocated port 17794 for RTP instance '0x7f77a42606f8' [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:354 ast_rtp_instance_new: RTP instance '0x7f77a42606f8' is setup and ready to go [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:345 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f77a4005e98' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:483 ast_rtp_new: Allocated port 11658 for RTP instance '0x7f77a4005e98' [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:354 ast_rtp_instance_new: RTP instance '0x7f77a4005e98' is setup and ready to go [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:2394 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f77a4005e98' [2011-10-19 13:24:16] DEBUG[19107]: res_rtp_asterisk.c:2394 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f77a42606f8' == Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:4934 do_setnat: Setting NAT on RTP to Off [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:4938 do_setnat: Setting NAT on VRTP to Off [2011-10-19 13:24:16] DEBUG[19107]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '542124' into... [2011-10-19 13:24:16] DEBUG[19107]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '542124' and port ''. [2011-10-19 13:24:16] WARNING[19107]: acl.c:708 ast_ouraddrfor: Cannot connect [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 127.0.1.1:5060 [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6845 sip_new: *** Our native formats are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6846 sip_new: *** Joint capabilities are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6847 sip_new: *** Our capabilities are 0x38000e (gsm|ulaw|alaw|h263|h263p|h264) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6848 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6850 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:6876 sip_new: This channel can handle video! HOLLYWOOD next! [2011-10-19 13:24:16] DEBUG[19107]: rtp_engine.c:1454 ast_rtp_instance_early_bridge_make_compatible: Seeded SDP of 'SIP/542124-0000002d' with that of 'SIP/315166-0000002b' [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable DIALEDTIME. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable DIALSTATUS. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable AVAILCAUSECODE. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable AVAILSTATUS. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable AVAILORIGCHAN. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable AVAILCHAN. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable ARG3. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable ARG2. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable ARG1. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable SIPCALLID. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [2011-10-19 13:24:16] DEBUG[19107]: channel.c:6041 ast_channel_inherit_variables: Not copying variable SIPURI. [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:5485 sip_call: Outgoing Call for [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:5750 update_call_counter: Updating call counter for outgoing call [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:10957 add_sdp: This call needs video offers! [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:11007 add_sdp: ** Our capability: 0x38000e (gsm|ulaw|alaw|h263|h263p|h264) Video flag: False Text flag: False [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:11008 add_sdp: ** Our prefcodec: 0x8 (alaw) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:11117 add_sdp: -- Done with adding codecs to SDP [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:11256 add_sdp: Done building SDP. Settling with this capability: 0x38000e (gsm|ulaw|alaw|h263|h263p|h264) [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:3054 initialize_initreq: Initializing initreq for method INVITE - callid 7b49340807f334647c0b3aba57333db0@127.0.1.1:5060 [2011-10-19 13:24:16] DEBUG[19107]: chan_sip.c:3325 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 0.8.69.172:5060 [2011-10-19 13:24:16] WARNING[19107]: chan_sip.c:3351 __sip_xmit: sip_xmit of 0x7f778803fcf0 (len 929) to 0.8.69.172:5060 returned -1: Invalid argument -- Called SIP/542124 [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:3586 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #3792)) [2011-10-19 13:24:16] DEBUG[18853]: chan_sip.c:3325 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 0.8.69.172:5060 [2011-10-19 13:24:16] WARNING[18853]: chan_sip.c:3351 __sip_xmit: sip_xmit of 0x7f778803fcf0 (len 929) to 0.8.69.172:5060 returned -1: Invalid argument [2011-10-19 13:24:17] DEBUG[18853]: chan_sip.c:3586 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #3792)) [2011-10-19 13:24:17] DEBUG[18853]: chan_sip.c:3325 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 0.8.69.172:5060 [2011-10-19 13:24:17] WARNING[18853]: chan_sip.c:3351 __sip_xmit: sip_xmit of 0x7f778803fcf0 (len 929) to 0.8.69.172:5060 returned -1: Invalid argument [2011-10-19 13:24:19] DEBUG[18853]: chan_sip.c:3586 retrans_pkt: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #3792)) [2011-10-19 13:24:19] DEBUG[18853]: chan_sip.c:3325 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 0.8.69.172:5060 [2011-10-19 13:24:19] WARNING[18853]: chan_sip.c:3351 __sip_xmit: sip_xmit of 0x7f778803fcf0 (len 929) to 0.8.69.172:5060 returned -1: Invalid argument [2011-10-19 13:24:23] DEBUG[18853]: chan_sip.c:3586 retrans_pkt: ** SIP timers: Rescheduling retransmission 5 to 8000 ms (t1 500 ms (Retrans id #3792)) [2011-10-19 13:24:23] DEBUG[18853]: chan_sip.c:3325 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 0.8.69.172:5060 [2011-10-19 13:24:23] WARNING[18853]: chan_sip.c:3351 __sip_xmit: sip_xmit of 0x7f778803fcf0 (len 929) to 0.8.69.172:5060 returned -1: Invalid argument By: Luke H (luckman212) 2011-12-29 20:36:31.543-0600 Sorry to comment on a 'closed' issue, but since this patch passed review, I am curious when it will be applied to a release branch? It doesn't seem to be in 1.8.8.0 as far as I can tell? Is that an oversight? | ||||||||||||