Reisegiganten / libvmod-abtest

A varnish vmod to get weighted random values for A/B testing, with a dynamic configuration.
Other
4 stars 3 forks source link

Mac OSX: call to abtest.rand("myrule") "crashes" varnish #2

Closed huguesalary closed 12 years ago

huguesalary commented 12 years ago

On mac osx 10.6.8 varnishd (varnish-3.0.2 revision 55e70a4) after succefully compiling and importing your vmod, varnish fails to give an answer to the browser:

Answer from the browser

VCL Config

#import abtest;

vcl_recv() {
    abtest.set_rule("^test", "a:80;b:20;300;");
}

vcl_deliver() {
    set resp.http.X-Req = "abtesting=" + abtest.get_rand("test");
}

varnishlog output

 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349497728 1.0
 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349497731 1.0
14 BackendOpen  b default 127.0.0.1 64749 127.0.0.1 8080
14 TxRequest    b GET
14 TxURL        b /
14 TxProtocol   b HTTP/1.1
14 TxHeader     b Host: xxx.dyndns.org
14 TxHeader     b Pragma: no-cache
14 TxHeader     b User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_6_8) AppleWebKit/537.4 (KHTML, like Gecko) Chrome/22.0.1229.79 Safari/537.4
14 TxHeader     b Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
14 TxHeader     b Accept-Language: en-US,en;q=0.8,fr;q=0.6
14 TxHeader     b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.3
14 TxHeader     b Cookie: __unam=d8cb8fc-1373474e385-fb57489-1; __utmx=61625407.; __utmxx=61625407.; __utmx=1.; __utmxx=1.; __utma=1.55154200.1338591865.1339534723.1340041951.9; __utmz=1.1338591865.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); __utma=61625407.20100163
14 TxHeader     b X-Device: desktop
14 TxHeader     b X-Varnish: 8401889
14 TxHeader     b Accept-Encoding: gzip
14 RxProtocol   b HTTP/1.1
14 RxStatus     b 200
14 RxResponse   b OK
14 RxHeader     b Date: Sat, 06 Oct 2012 04:28:50 GMT
14 RxHeader     b Server: Apache/2.2.14 (Unix) DAV/2 mod_ssl/2.2.14 OpenSSL/0.9.8l PHP/5.3.1 mod_perl/2.0.4 Perl/v5.10.1
14 RxHeader     b X-Powered-By: PHP/5.3.1
14 RxHeader     b Expires: Thu, 19 Nov 1981 08:52:00 GMT
14 RxHeader     b Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
14 RxHeader     b Pragma: no-cache
14 RxHeader     b Set-Cookie: frontend=eec4e97e71dd19c761371926746b4c56; expires=Sun, 07-Oct-2012 04:28:50 GMT; path=/; domain=.xxx.dyndns.org; httponly
14 RxHeader     b X-Magento-Doesi: 1
14 RxHeader     b Transfer-Encoding: chunked
14 RxHeader     b Content-Type: text/html; charset=UTF-8
14 Fetch_Body   b 3(chunked) cls 0 mklen 1
14 Length       b 8705
14 BackendReuse b default
 0 WorkThread   - 0x100586ae0 start
 0 CLI          - Rd vcl.load "boot" ./vcl.u8HZOjUl.so
 0 CLI          - Wr 200 36 Loaded "./vcl.u8HZOjUl.so" as "boot"
 0 CLI          - Rd vcl.use "boot"
 0 CLI          - Wr 200 0 
 0 CLI          - Rd start
 0 Debug        - "Acceptor poll space increased to 512"
 0 Debug        - "Acceptor is poll"
 0 CLI          - Wr 200 0 
 0 WorkThread   - 0x106586ae0 start
 0 WorkThread   - 0x106609ae0 start
 0 WorkThread   - 0x10668cae0 start
 0 WorkThread   - 0x10670fae0 start
 0 WorkThread   - 0x106792ae0 start
 0 WorkThread   - 0x108080ae0 start
 0 WorkThread   - 0x108103ae0 start
 0 WorkThread   - 0x108186ae0 start
 0 WorkThread   - 0x108209ae0 start
 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349497735 1.0
 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349497738 1.0

Important note

Removing the line set resp.http.X-Req = "abtesting=" + abtest.get_rand("test"); in vcl_deliver() makes everything work. So it must be related to that.

huguesalary commented 12 years ago

I also confirm this bug on debian 6.0.5 but this time with varnish-3.0.3 (as opposed to 3.0.2 in my first report).

$uname -a
Linux 2.6.32-5-amd64 #1 SMP Sun May 6 04:00:17 UTC 2012 x86_64 GNU/Linux
$varnishd -V
varnishd (varnish-3.0.3 revision 9e6a70f)

Also worth noting that in order to be able to use your vmod on debian, I had to patch the source and replace strlcpy by strncpy. I "dumb patched" it without thinking more about the side effects of replacing strlcpy by strncpy, but I doubt that this bug is caused by my patch because I also have this bug on Mac OSX.

Varnishlog

 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349549455 1.0
13 BackendOpen  b default 192.168.99.176 33774 192.168.99.202 8080
13 TxRequest    b GET
13 TxURL        b /
13 TxProtocol   b HTTP/1.1
13 TxHeader     b Host: xxx.dyndns.org
13 TxHeader     b Pragma: no-cache
13 TxHeader     b User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_6_8) AppleWebKit/537.4 (KHTML, like Gecko) Chrome/22.0.1229.79 Safari/537.4
13 TxHeader     b Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
13 TxHeader     b Accept-Language: en-US,en;q=0.8,fr;q=0.6
13 TxHeader     b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.3
13 TxHeader     b Cookie: __unam=d8cb8fc-1373474e385-fb57489-1; __utmx=61625407.; __utmxx=61625407.; __utmx=1.; __utmxx=1.; __utma=1.55154200.1338591865.1339534723.1340041951.9; __utmz=1.1338591865.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); __utma=61625407.20100163
13 TxHeader     b X-Device: desktop
13 TxHeader     b X-Varnish: 1300113608
13 TxHeader     b Accept-Encoding: gzip
13 RxProtocol   b HTTP/1.1
13 RxStatus     b 200
13 RxResponse   b OK
13 RxHeader     b Date: Sat, 06 Oct 2012 18:50:56 GMT
13 RxHeader     b Server: Apache/2.2.14 (Unix) DAV/2 mod_ssl/2.2.14 OpenSSL/0.9.8l PHP/5.3.1 mod_perl/2.0.4 Perl/v5.10.1
13 RxHeader     b X-Powered-By: PHP/5.3.1
13 RxHeader     b Expires: Thu, 19 Nov 1981 08:52:00 GMT
13 RxHeader     b Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
13 RxHeader     b Pragma: no-cache
13 RxHeader     b Set-Cookie: frontend=eec4e97e71dd19c761371926746b4c56; expires=Sun, 07-Oct-2012 18:50:57 GMT; path=/; domain=.xxx.dyndns.org; httponly
13 RxHeader     b X-Magento-Doesi: 1
13 RxHeader     b Transfer-Encoding: chunked
13 RxHeader     b Content-Type: text/html; charset=UTF-8
13 Fetch_Body   b 3(chunked) cls 0 mklen 1
13 Length       b 8710
13 BackendReuse b default
 0 WorkThread   - 0x7f4a55abaac0 start
 0 CLI          - Rd vcl.load "boot" ./vcl.9TIv_wLT.so
 0 CLI          - Wr 200 36 Loaded "./vcl.9TIv_wLT.so" as "boot"
 0 CLI          - Rd vcl.use "boot"
 0 CLI          - Wr 200 0 
 0 WorkThread   - 0x7f4a52ee9ac0 start
 0 CLI          - Rd start
 0 Debug        - "Acceptor is epoll"
 0 CLI          - Wr 200 0 
 0 WorkThread   - 0x7f4a50ee5ac0 start
 0 WorkThread   - 0x7f4a506e4ac0 start
 0 WorkThread   - 0x7f4a4fee3ac0 start
 0 WorkThread   - 0x7f4a4f6e2ac0 start
 0 WorkThread   - 0x7f4a4eee1ac0 start
 0 WorkThread   - 0x7f4a4e6e0ac0 start
 0 WorkThread   - 0x7f4a4dedfac0 start
 0 WorkThread   - 0x7f4a4d6deac0 start
 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349549460 1.0
 0 CLI          - Rd ping
 0 CLI          - Wr 200 19 PONG 1349549463 1.0
xav commented 12 years ago

I think I fixed that now. I forgot to cast an unsigned operation to double, which resulted in a way out of bound index, and ultimately a dead process. I guess I was "lucky" up till now with the output of drand48 since it never crashed before... Thanks for the feedback, hope it will work for you now :)

/X