[Home]

Summary:ASTERISK-12252: [patch] Added CURL() Function Timeout Argument
Reporter:David Van Ginneken (davevg)Labels:
Date Opened:2008-06-23 16:12:19Date Closed:2008-09-05 14:02:49
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Functions/func_curl
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 20080709__bug12920.diff.txt
( 1) 20080711__bug12920__2.diff.txt
( 2) 20080711__bug12920.diff.txt
( 3) 20080806__bug12920.diff.txt
( 4) 20080904__bug12920.diff.txt
( 5) asterisk.21743
( 6) asterisk.21862
( 7) backtrace_v2.txt
( 8) backtrace.txt
( 9) func_curl.v3.diff
Description:If you have a long running web script the CURL function is currently hard coded to timeout after 180 seconds.  This patch adds a 3rd parameter to the function which when set overrides the 180 second default.

Example usage:
exten => 1,1,Set(foo=${CURL(http://127.0.0.1/test.pl,,3)})
Which will set a timeout of 3 seconds on the CURL call.

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

test.pl consists of the following for testing.  You can adjust the $pause variable to the number of seconds to sleep.

#!/usr/bin/perl
use CGI;
use strict;
my $r = new CGI;
my $response = 'OK';
print $r->header(-type=>'text/html');
my $pause = 200;
for (1..$pause){
       print ".";
       sleep(1);
}
print $response;
Comments:By: Tilghman Lesher (tilghman) 2008-06-23 17:18:12

I'm not sure I like this solution.  This would mean that you would be unable to have commas in the POST data, which is not a reasonable assumption.  I'd be much happier with either a variable specifying the timeout or a prefixed option.

By: David Van Ginneken (davevg) 2008-06-23 17:47:11

Fair enough, I'll rework it to read a channel variable tomorrow and re-submit a patch.  Would this be considered a feature or a bug?  If a bug I can also submit the backports to 1.4 and 1.2 when complete.

By: Tilghman Lesher (tilghman) 2008-06-23 17:51:08

This would be considered a feature add.

By: David Van Ginneken (davevg) 2008-06-23 18:15:14

Can the last patch be removed?  I forgot to add 1 check, will resubmit shortly

By: Tilghman Lesher (tilghman) 2008-06-24 11:43:28

Looking over the bounty, it appears that they also want other options to be settable.  You might want to change this even more, possibly by creating a CURLOPT() function, whose values can be set, e.g.

Set(CURLOPT(timeout)=30)
Set(CURLOPT(connecttimeout)=10)
Set(CURLOPT(proxy)=http://foo)
Set(CURLOPT(proxytype)=http)
Set(CURLOPT(proxyport)=9138)
etc.

There are a full list of options available on the libcurl API page:
http://curl.haxx.se/libcurl/c/curl_easy_setopt.html
(although there are probably a few that aren't terribly useful)

I'd store the data on a channel datastore structure, which is allocated per-channel.  Perhaps even if the channel structure is not passed into the function, it should set a global value (which channels will inherit, if not overridden directly).  Those global values could be stored directly within variables within the module itself.

By: sohosys (sohosys) 2008-06-24 22:24:37

We posted the bounty, and the version of the patch provided for earlier versions is great (1.2,1.4) using the CURL_TIMEOUT channel variable as suggested by Corydon76. Since we use CURL exclusively for CNAM queries we needed to make sure the function returned a value before SIP timers expired, even if that means returning a null value. The request to set other options was made under the assumption that all of the options could be passed in one string like it is with the command line curl, but upon further review we learned that libcurl requires each option to be set explicitly. When that is considered the simpler solution of just setting the timeout better met our needs. The other options are rather obscure, and unless someone else can show where there would be additional value I would argue that the timeout is all that is really needed based on how I have seen this function used in the past by others, and in our current application. The default 180 second timer is far too long for anything that happens in real time in any dialplan I have seen. My vote (FWIW) would be to move forward with the single channel variable CURL_TIMEOUT. If you consider the fact that all SIP timers can expire while the CURL function is waiting for a hung web application, resulting in a dropped channel, many would consider the current 180 second timer a bug. The situations where the time is needed are few and far between. All of these conditions do not result in a failed call because libcurl returns very quickly; failed DNS query, no route to destination host, connection refused by remote host, any http error, etc. The ONLY situation where we have had calls drop is when the remote web server allows a connection to be established but does not return data or close the connection before the channel progress timers expire as in the case of a hung app or slow/hung underlying database. The sample perl script shown in this thread is perfect for simulating the problem.

By: Tilghman Lesher (tilghman) 2008-06-24 23:16:55

My intent in making the suggestion was not in "moving the goal posts" as it were, but merely to note that there are additional options that some people may find useful (such as being able to set up CURL to use a proxy).  I find it interesting enough that it will get coded whether davevg decides to or not, but I felt it would be more fair to offer him the opportunity, before I ran with it, especially since it would replace the work that he has done already with this patch.

By: David Van Ginneken (davevg) 2008-06-25 07:54:42

I understand where Tilghman is coming from.  There are other portions of asterisk which can benefit from the added function to set the options.  res_config_curl comes to mind.  That said, I will try to get the suggested implementation functional, but it may take a bit of time and multiple iterations before it is in a state of being able to be merged.

By: sohosys (sohosys) 2008-06-25 08:15:14

Fair enough, I will hold off on making the patches for 1.2 and 1.4 publically available until we see where this goes, and if you do decide to use the proposed CURLOPT() structure we would try and back port at least the CURLOPT(timeout) syntax to 1.2 and 1.4 to maintain forward dialplan compatibility. A couple of other users have expressed interest in the simple patch, presumably because they have had the same issues we have had, and 1.2 and 1.4 seem to be prevalent in my circle. We use a large national CNAM provider that many others use as well, and they recently had an outage that allowed connections, returned no data, and didnot drop the connection, resulting in failed calls for anyone using Asterisk CURL to do the queries. Our concern has been resolved, but we fully support the greater good.

By: Tilghman Lesher (tilghman) 2008-06-25 08:41:44

On res_config_curl, this may provide the impetus to fix curl within Asterisk, such that the two modules rely on a res_curl backend module (which controls the global initialization) and let res_config_curl not depend upon func_curl (which was always kind of a hack anyway).  The reason why would be to ensure that if you need different options for res_config_curl than are needed for CURL queries from the dialplan, that they don't conflict.  I could see some fairly nasty bugs that could appear if this was the case, under the current schema.

By: Tilghman Lesher (tilghman) 2008-07-09 18:09:06

Since I haven't seen any progress in 2 weeks, I've gone ahead and started on an implementation.  This patch hasn't yet been tested, but I will take whatever testing I can get.

By: David Van Ginneken (davevg) 2008-07-10 10:44:29

Thanks,  Sorry I have not been able to get this done yet.  Is the patch provided against /trunk, or /branches/1.6.0?  I'll install the correct version apply the patch, then test the various options for you here to verify it works as well as put it under some sipp load.

By: Tilghman Lesher (tilghman) 2008-07-10 10:47:38

As this is a new feature, it's against trunk.

By: David Van Ginneken (davevg) 2008-07-11 14:26:58

Ok finally got around to trying to test this.  Few issues:

The current patch will not compile on centos5 due to curl version number differences:
curl --version
curl 7.15.5 (i686-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5
Protocols: tftp ftp telnet dict ldap http file https ftps
Features: GSS-Negotiate IDN IPv6 Largefile NTLM SSL libz

uname -a
Linux asterisk 2.6.18-8.1.10.el5 #1 SMP Thu Sep 13 12:17:54 EDT 2007 i686 i686 i386 GNU/Linux


The problem is CURLOPT_TIMEOUT_MS and CURLOPT_CONNECTTIMEOUT_MS.  Both the _MS options were added in 7.16.2.  The standard whole second timeouts appear to be there.

After removing the _MS option and changing the type from OT_INTEGER_MS to OT_INTEGER it compiled fine.  Another small change is the cookie parameter should be CURLOPT_COOKIE.

In testing I 1st wanted to test the httptimeout option.  So I set the dialplan up like this:
exten => 77,1,Answer()
exten => 77,n,NoOp(${EPOCH})
exten => 77,n,Set(CURLOPT(httptimeout)=10)
exten => 77,n,Set(foo=${CURL(http://192.168.175.97/nascar/test.pl)})
exten => 77,n,NoOp(${EPOCH})
exten => 77,n,Hangup

This seems to ignore the timeout, but when it does actually get a return from the page, it cores.

Backtrace will be attached to this bug shortly.

By: Tilghman Lesher (tilghman) 2008-07-11 15:55:40

Patch updated.  Let's see if that works better for you.

By: David Van Ginneken (davevg) 2008-07-11 18:35:59

Seems to core in the same general place.  New backtrace attached.  

It makes the call out to the web page, once the web page is complete asterisk cores.

By: Tilghman Lesher (tilghman) 2008-07-12 06:56:20

Crash tracked down and nipped in the bud.  Let me know if you have any more problems.

By: David Van Ginneken (davevg) 2008-07-13 11:38:29

Tested it briefly this weekend.  Seems to have a core in a different place now, but at the same time.  When the return from the web result is retrieved.  But.. It is not on every call.  Sometimes the return works, sometimes it just cores.  It still doesn't seem to honor the httptimeout value I'm passing (Unless I'm setting it wrong) and waits until the page returns.  For example, I set the web page to return after 20 seconds, and set the httptimeout to be 10.  It comes back to the dialplan in 20.  I'll update to the latest svn again, currently on 130167, and get more details tomorrow.  

#0  0x00dcd402 in __kernel_vsyscall ()
#1  0x00700ba0 in raise () from /lib/libc.so.6
#2  0x007024b1 in abort () from /lib/libc.so.6
#3  0x00736dfb in __libc_message () from /lib/libc.so.6
#4  0x0073eaa6 in _int_free () from /lib/libc.so.6
ASTERISK-1  0x00741fc0 in free () from /lib/libc.so.6
ASTERISK-2  0x080e5347 in pbx_destroy (p=0x9657198) at pbx.c:988
ASTERISK-3  0x080eea17 in __ast_pbx_run (c=0x965c610) at pbx.c:3881
ASTERISK-4  0x080eeced in pbx_thread (data=0x965c610) at pbx.c:3974
ASTERISK-5  0x0813c14a in dummy_start (data=0x965c590) at utils.c:1024
ASTERISK-6 0x0084e45b in start_thread () from /lib/libpthread.so.0
ASTERISK-7 0x007a624e in clone () from /lib/libc.so.6

By: David Van Ginneken (davevg) 2008-07-14 08:19:13

Did an svn update this morning on trunk, and I no longer receive any crashes.  The only issue that remains is the options set by Set(CURLOPT()=) seem to be ignored.
I've tried the following options and looked at the apache and squid proxy logs with no change:
exten => 77,1,Answer()
exten => 77,n,NoOp(${EPOCH})
exten => 77,n,Set(CURLOPT(httptimeout)=10)
exten => 77,n,Set(CURLOPT(conntimeout)=10)
exten => 77,n,Set(CURLOPT(proxy)=192.168.175.97)
exten => 77,n,Set(CURLOPT(proxytype)=http)
exten => 77,n,Set(CURLOPT(proxyport)=3128)
exten => 77,n,Set(CURLOPT(referer)=127.0.0.1)
exten => 77,n,Set(CURLOPT(useragent)="Mozilla/4.0 test")
exten => 77,n,Set(foo=${CURL(http://192.168.175.97/nascar/test.pl)})
exten => 77,n,NoOp(${EPOCH})
exten => 77,n,Hangup



By: Tilghman Lesher (tilghman) 2008-08-06 16:58:21

Finally had some time to track this down.  New patch uploaded, ready for additional testing.

By: David Van Ginneken (davevg) 2008-08-11 13:45:15

I've been out on vacation,  I'll see what I can do as far as testing this sometime this week once I get caught up with work.  I'll let you know how testing goes, I think I'll be able to test most options to verify functionality.

By: David Van Ginneken (davevg) 2008-08-13 13:35:32

URL: http://svn.digium.com/svn/asterisk/trunk
Repository Root: http://svn.digium.com/svn/asterisk
Repository UUID: 614ede4d-c843-0410-af14-a771ab80d22e
Revision: 137454
Node Kind: directory
Schedule: normal
Last Changed Author: seanbright
Last Changed Rev: 137406
Last Changed Date: 2008-08-13 10:41:49 -0400 (Wed, 13 Aug 2008)


Backtrace:

(gdb) bt full
#0  0x00914402 in __kernel_vsyscall ()
No symbol table info available.
#1  0x003b8d20 in raise () from /lib/libc.so.6
No symbol table info available.
#2  0x003ba631 in abort () from /lib/libc.so.6
No symbol table info available.
#3  0x003f0e6b in __libc_message () from /lib/libc.so.6
No symbol table info available.
#4  0x003f8b16 in _int_free () from /lib/libc.so.6
No symbol table info available.
ASTERISK-1  0x003fc070 in free () from /lib/libc.so.6
No symbol table info available.
ASTERISK-2  0x04e62ff0 in curl_instance_cleanup (data=0x84a3758) at func_curl.c:376
       curl = (CURL **) 0x84a3758
ASTERISK-3  0x00508b8c in __nptl_deallocate_tsd () from /lib/libpthread.so.0
No symbol table info available.
ASTERISK-4  0x00509479 in start_thread () from /lib/libpthread.so.0
No symbol table info available.
ASTERISK-5  0x00460dbe in clone () from /lib/libc.so.6
No symbol table info available.


With the last patch installed I get the above core backtrace.  If I revert the patch and use the unpatched curl, it does not core.

By: Tilghman Lesher (tilghman) 2008-08-13 15:37:27

Could you run this under valgrind, or provide me with the options that you set to cause this crash?  It's clearly memory corruption happening, but I'm not sure that func_curl.c is the cause, as I reproduced the crash once, then I tried it again, and it failed to crash twice.

By: David Van Ginneken (davevg) 2008-08-13 15:48:39

The options I used were in the previous post above.  I'll read through the valgrind docs and figure out how to get that working, but likely will not be able to report back until Friday.

By: Tilghman Lesher (tilghman) 2008-08-13 16:08:42

valgrind --tool=memcheck --log-file=asterisk /usr/sbin/asterisk -vvvcg

By: David Van Ginneken (davevg) 2008-08-14 08:30:50

asterisk.21743 crashed after 3 tries, The curl call didn't return anything the 1st 2 instances.
asterisk.21862 crashed on the 1st try.

By: Tilghman Lesher (tilghman) 2008-08-14 09:08:50

Strange as it may seem, you're actually seeing a crash relating to a double free() within the SIP driver.  No idea why you're not getting that crash without this patch, but it may simply be a matter of timing.

By: Tilghman Lesher (tilghman) 2008-09-04 09:25:00

Added another patch that does more strict checking of memory allocations.

By: David Van Ginneken (davevg) 2008-09-04 09:34:30

I'll test this either later today or tomorrow and report back.  (Also going to update to the latest svn)

By: David Van Ginneken (davevg) 2008-09-05 13:41:09

I ran 50-100 calls through the lastest svn (141327) and the last patch from yesterday and could not reproduce any crashes.  I can verify the following options were tested and working on my test system:

httptimeout, works
conntimeout, unable to test, if i changed the proxy port to an invalid port it returned immediately
proxy, works
proxytype=http  works (I used squid proxy)
proxyport, works
referer, works
useragent, works

By: Digium Subversion (svnbot) 2008-09-05 14:02:46

Repository: asterisk
Revision: 141328

U   trunk/CHANGES
U   trunk/funcs/func_curl.c

------------------------------------------------------------------------
r141328 | tilghman | 2008-09-05 14:02:46 -0500 (Fri, 05 Sep 2008) | 8 lines

Add the CURLOPT dialplan function, which permits setting various options for
use with the CURL dialplan function.
(closes issue ASTERISK-12252)
Reported by: davevg
Patches:
      20080904__bug12920.diff.txt uploaded by Corydon76 (license 14)
Tested by: Corydon76, davevg

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=141328