Re: Release date for Privoxy 3.0.20 beta

On 12/31/12, Fabian Keil <[email protected]> wrote:
> Lee <[email protected]> wrote:
>
>> On 12/29/12, Fabian Keil <[email protected]> wrote:
>> > I believe there are enough changes in CVS to warrant a new release.
>> >
>> > As several of the changes are HTTP-related and affect pretty
>> > much every request, I think it should be a beta.
>> >
>> > I propose we release Privoxy 3.0.20 beta in the middle of
>> > January and 3.0.21 stable a couple of weeks later.
>> >
>> > At least the beta may also be a good opportunity to enable
>> > keep-alive-timeout and tolerate-pipelining in the default
>> > config.
>> >
>> > Any opinions?
>>
>> I don't think the windows version is ready for beta :(
>>
>> I apologize - I haven't been keeping up with the changes being made to
>> Privoxy.  I just tried the latest from CVS and it tends to hang the
>> browser.  This hangs consistently:
>
> Oops.
>
>> restart privoxy, restart firefox, clear the cache, go here
>>   http://www.microsoft.com/en-us/download/default.aspx
>> then click on the link for the directx download
>>   http://www.microsoft.com/en-us/download/details.aspx?id=35
>>
>> The 2nd page never displays
>>
>> I'll send the log + my config in a unicast
>
> Thanks.
>
> Please try the attached patch. If it doesn't help,

browser immediately comes back with an error message about the proxy
closing the connection

> please temporarily
> reduce drain_and_close_socket() to the close_socket() call at the end.

That works, but privoxy complains about 'The client side of the
connection on socket NNN got closed without sending a complete request
line.' when clicking on the link to the 2nd page.

I changed data_is_available:
   /* LR was: return ((n == 1) && (1 == recv(fd, buf, 1, MSG_PEEK))); */
   status =  recv(fd, buf, 1, MSG_PEEK);
   log_error(LOG_LEVEL_INFO, "data_is_available: socket %d select=%d
recv=%d", fd, n, status);   /* LR */
   return ((n == 1) && (1 == status));
}


2012-12-31 16:31:25.155 00000d20 Request:
http://i.microsoft.com/global/ImageStore/PublishingImages/FY13/Asset/features/WinEval_V2_1127_920x330_EN_US.jpg
2012-12-31 16:31:25.233 00000ebc Info: data_is_available: socket 556
select=1 recv=1
2012-12-31 16:31:25.233 00000ebc Info: data_is_available: socket 556
select=1 recv=1
2012-12-31 16:31:25.233 00000ebc Request:
http://i.microsoft.com/global/ImageStore/PublishingImages/FY13/Asset/features/VS_1127_920x330_EN_US.jpg
2012-12-31 16:31:29.304 00000dc8 Info: data_is_available: socket 1696
select=1 recv=0
2012-12-31 16:31:29.304 00000dc8 Error: The client side of the
connection on socket 1696 got closed without sending a complete
request line.
2012-12-31 16:31:29.304 00000dc8 Info: data_is_available: socket 1696
select=1 recv=0
2012-12-31 16:31:30.084 00000d20 Info: data_is_available: socket 192
select=1 recv=1
2012-12-31 16:31:30.084 00000d20 Info: data_is_available: socket 192
select=1 recv=1
2012-12-31 16:31:30.084 00000d20 Request:
http://www.microsoft.com/en-us/download/details.aspx?id=35
2012-12-31 16:31:30.552 00000d20 Info: data_is_available: socket 192
select=1 recv=1
2012-12-31 16:31:30.552 00000d20 Info: data_is_available: socket 192
select=1 recv=1
2012-12-31 16:31:30.568 00000d20 Request:
http://i.microsoft.com/en-us/download/style.cssx?k=~/shared/templates/components/mscomViews/grid/grid-css.aspx;~/shared/templates/components/mscomViews/controls/featureitem/featureItem-css.aspx;~/shared/templates/components/mscomViews/List/list-css.aspx&sc=/en-us/download/site.config&pc=/en-us/download/PageConfig/details.config.xml&v=1185941585
2012-12-31 16:31:30.552 00000ea0 Info: data_is_available: socket 420
select=0 recv=1
2012-12-31 16:31:30.568 00000ea0 Info: data_is_available: socket 420
select=1 recv=1
2012-12-31 16:31:30.552 000006cc Info: data_is_available: socket 880
select=0 recv=1
2012-12-31 16:31:30.568 000006cc Info: data_is_available: socket 880
select=1 recv=1
2012-12-31 16:31:30.552 00000d98 Info: data_is_available: socket 476
select=0 recv=1
2012-12-31 16:31:30.583 00000d98 Info: data_is_available: socket 476
select=1 recv=1
2012-12-31 16:31:30.552 000006f8 Info: data_is_available: socket 532
select=0 recv=1
2012-12-31 16:31:30.583 000006f8 Info: data_is_available: socket 532
select=1 recv=1
2012-12-31 16:31:30.552 00000ddc Info: data_is_available: socket 808
select=0 recv=1
2012-12-31 16:31:30.583 00000ddc Info: data_is_available: socket 808
select=1 recv=1
2012-12-31 16:31:30.552 0000068c Info: data_is_available: socket 428
select=0 recv=1
2012-12-31 16:31:30.552 00000c08 Info: data_is_available: socket 668
select=0 recv=1
2012-12-31 16:31:30.552 00000140 Info: data_is_available: socket 620
select=0 recv=1

> My impression is that draining sockets when there is no data
> available causes problems:

I don't know about when there is no data available - in this case
there is.  I tried logging what got drained and it was the request for
the new page:
2012-12-31 14:51:19.981 00000ff4 Request:
http://i.microsoft.com/global/ImageStore/PublishingImages/FY13/Asset/features/VS_1127_920x330_EN_US.jpg
2012-12-31 14:51:30.339 00000130 Info: data_is_available: socket 192
select=0 recv=1
2012-12-31 14:51:30.339 00000130 Info: data_is_available: socket 192
select=1 recv=1
2012-12-31 14:51:30.339 00000130 Info: socket 192 drained 500 bytes:
GET http://www.microsoft.com/en-us/download/details.aspx?id=35
HTTP/1.1

Host: www.microsoft.com

User-Agent: Mozilla/5.0 (Windows NT 6.0; WOW64; rv:17.0)
Gecko/20100101 Firefox/17.0

Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8

Accept-Language: en-US,en;q=0.5

Accept-Encoding: gzip, deflate

Proxy-Connection: keep-alive

Referer: http://www.microsoft.com/en-us/download/default.aspx

Cookie: MC0=1xxxxxxxxxxxx;
WT_FPC=id=2xxxxxxxxxxxx62fceaxxxxxxxxxxxx5:lv=xxxxxxxxxxxx
2012-12-31 14:51:30.370 00000130 Info: socket 192 drained 59 bytes:
9:ss=1xxxxxxxxxxxx; WT_NVR=0=/:1=en-us:2=en-us/download

2012-12-31 14:52:43.784 0000087c Info: data_is_available: socket 1960
select=1 recv=0
2012-12-31 14:52:43.799 0000087c Error: The client side of the
connection on socket 1960 got closed without sending a complete
request line.


And then, after clicking on another two links, firefox complains about:

The connection was reset
          The connection to the server was reset while the page was loading.


> fk@r500 /tmp/privoxy-logs $privoxy-log-parser.pl --shorten-thread-ids
> privoxy-hang.txt  | grep 001 | tail -n 2
> 12:26:13.335 001 Connect: Closing client socket 256. Keep-alive: 1. Socket
> alive: 1. Data available: 0. Configuration file change detected: 0. Requests
> received: 5.
> 12:36:21.583 001 Connect: Drained 559 bytes before closing socket 256
>
> It looks like Privoxy is waiting on the socket until new data arrives,
> while the intended behaviour is to merely drain whatever data is available
> at the time the function is called and otherwise close the socket right
> away.

*sigh*  I'm still trying to follow the code :(

Lee

------------------------------------------------------------------------------
Master Visual Studio, SharePoint, SQL, ASP.NET, C# 2012, HTML5, CSS,
MVC, Windows 8 Apps, JavaScript and much more. Keep your skills current
with LearnDevNow - 3,200 step-by-step video tutorials by Microsoft
MVPs and experts. SALE $99.99 this month only -- learn more at:
http://p.sf.net/sfu/learnmore_122412