On Wed, Oct 22, 2008 at 08:19:16PM +0100, Mark Hindley wrote: > I didn't like the try again part of the patch. The point of this > function is to prevent a DOS. I could see that by keeping a socket > open, but not sending anything, you could create exactly that.
gotcha. > I really wish I could reproduce this -- it would help a lot. > Alternatively, debug info from you from when it does. Can you enable it > to catch the next one? > > The 400 error is to the client not just in the log? it's actually only on the client side; the server just gets an empty line and doesn't even show the request for that particular debian package. On the client it looks like: aptmethod got 'http://debian/debian/pool/main/x/xfce4/xfce4_4.4.2.1_all.deb' aptmethod got 'http://debian/debian/pool/main/x/xfce4-session/xfce4-session_4.4.2-6_i386.deb' aptmethod error receiving 'http://debian/debian/pool/main/x/xfonts-100dpi/xfonts-100dpi_1.0.0-4_all.deb': '400 No Request Recieved' aptmethod got 'http://debian/debian/pool/main/x/xfonts-75dpi/xfonts-75dpi_1.0.0-4_all.deb' And here are the server logs corresponding to that session: Thu Oct 23 03:24:01 2008|debug [24232]: Package sent Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: GET /debian/pool/main/x/xfce4/xfce4_4.4.2.1_all.deb HTTP/1.1 Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Host: debian Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Connection: keep-alive Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: User-Agent: Debian APT-HTTP/1.3 (0.7.16) Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Thu Oct 23 03:24:01 2008|debug [24232]: Resolved request is /debian/pool/main/x/xfce4/xfce4_4.4.2.1_all.deb Thu Oct 23 03:24:01 2008|debug [24232]: new base file: xfce4_4.4.2.1_all.deb Thu Oct 23 03:24:01 2008|debug [24232]: looking for /srv/apt-cacher-debian/packages/xfce4_4.4.2.1_all.deb Thu Oct 23 03:24:01 2008|debug [24232]: Entering critical section : file download decision Thu Oct 23 03:24:01 2008|debug [24232]: HIT Thu Oct 23 03:24:01 2008|debug [24232]: Exiting critical section Thu Oct 23 03:24:01 2008|debug [24232]: checks done, can return now Thu Oct 23 03:24:01 2008|debug [24232]: Entering critical section : reading the header file Thu Oct 23 03:24:01 2008|debug [24232]: Exiting critical section Thu Oct 23 03:24:01 2008|debug [24232]: Header sent: HTTP/1.1 200 OK Connection: Keep-Alive Accept-Ranges: bytes ETag: "b7a0056-1688-447699c0bcd80" Content-Length: 5768 Content-Type: application/x-debian-package Last-Modified: Sun, 02 Mar 2008 00:47:02 GMT Thu Oct 23 03:24:01 2008|debug [24232]: ready to send contents of /srv/apt-cacher-debian/packages/xfce4_4.4.2.1_all.deb Thu Oct 23 03:24:01 2008|debug [24232]: read 5768 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 5768 (sum: 5768) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 0 bytes Thu Oct 23 03:24:01 2008|debug [24232]: fetcher released lock Thu Oct 23 03:24:01 2008|debug [24232]: read 0 bytes Thu Oct 23 03:24:01 2008|debug [24232]: Package sent Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: GET /debian/pool/main/x/xfce4-session/xfce4-session_4.4.2-6_i386.deb HTTP/1.1 Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Host: debian Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Connection: keep-alive Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: User-Agent: Debian APT-HTTP/1.3 (0.7.16) Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Thu Oct 23 03:24:01 2008|debug [24232]: Resolved request is /debian/pool/main/x/xfce4-session/xfce4-session_4.4.2-6_i386.deb Thu Oct 23 03:24:01 2008|debug [24232]: new base file: xfce4-session_4.4.2-6_i386.deb Thu Oct 23 03:24:01 2008|debug [24232]: looking for /srv/apt-cacher-debian/packages/xfce4-session_4.4.2-6_i386.deb Thu Oct 23 03:24:01 2008|debug [24232]: Entering critical section : file download decision Thu Oct 23 03:24:01 2008|debug [24232]: HIT Thu Oct 23 03:24:01 2008|debug [24232]: Exiting critical section Thu Oct 23 03:24:01 2008|debug [24232]: checks done, can return now Thu Oct 23 03:24:01 2008|debug [24232]: Entering critical section : reading the header file Thu Oct 23 03:24:01 2008|debug [24232]: Exiting critical section Thu Oct 23 03:24:01 2008|debug [24232]: Header sent: HTTP/1.1 200 OK Connection: Keep-Alive Accept-Ranges: bytes ETag: "41d0057-ec5d8-14f31ac0" Content-Length: 968152 Content-Type: application/x-debian-package Last-Modified: Tue, 20 May 2008 17:48:03 GMT Thu Oct 23 03:24:01 2008|debug [24232]: ready to send contents of /srv/apt-cacher-debian/packages/xfce4-session_4.4.2-6_i386.deb Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 65536) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 131072) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 196608) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 262144) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 327680) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 393216) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 458752) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 524288) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 589824) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 655360) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 720896) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 786432) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 851968) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 65536 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 65536 (sum: 917504) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 50648 bytes Thu Oct 23 03:24:01 2008|debug [24232]: wrote 50648 (sum: 968152) bytes Thu Oct 23 03:24:01 2008|debug [24232]: read 0 bytes Thu Oct 23 03:24:01 2008|debug [24232]: fetcher released lock Thu Oct 23 03:24:01 2008|debug [24232]: read 0 bytes Thu Oct 23 03:24:01 2008|debug [24232]: Package sent Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: got: Thu Oct 23 03:24:01 2008|debug [24232]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24232]: Clean up before exiting. Thu Oct 23 03:24:01 2008|debug [24232]: killing subprocess: 24235 Thu Oct 23 03:24:01 2008|debug [19281]: Connection from 10.0.0.163 Thu Oct 23 03:24:01 2008|debug [19281]: registered child process: 24236 Thu Oct 23 03:24:01 2008|debug [24236]: New Daemon connection Thu Oct 23 03:24:01 2008|debug [24236]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24236]: got: GET /debian/pool/main/x/xfonts-75dpi/xfonts-75dpi_1.0.0-4_all.deb HTTP/1.1 Thu Oct 23 03:24:01 2008|debug [24236]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24236]: got: Host: debian Thu Oct 23 03:24:01 2008|debug [24236]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24236]: got: Connection: keep-alive Thu Oct 23 03:24:01 2008|debug [24236]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24236]: got: User-Agent: Debian APT-HTTP/1.3 (0.7.16) Thu Oct 23 03:24:01 2008|debug [24236]: Processing a new request line Thu Oct 23 03:24:01 2008|debug [24236]: got: Thu Oct 23 03:24:01 2008|debug [24236]: Resolved request is /debian/pool/main/x/xfonts-75dpi/xfonts-75dpi_1.0.0-4_all.deb Thu Oct 23 03:24:01 2008|debug [24236]: new base file: xfonts-75dpi_1.0.0-4_all.deb Thu Oct 23 03:24:01 2008|debug [24236]: looking for /srv/apt-cacher-debian/packages/xfonts-75dpi_1.0.0-4_all.deb Thu Oct 23 03:24:01 2008|debug [24236]: Entering critical section : file download decision Thu Oct 23 03:24:01 2008|debug [24236]: HIT Thu Oct 23 03:24:01 2008|debug [24236]: Exiting critical section Thu Oct 23 03:24:01 2008|debug [24236]: checks done, can return now Thu Oct 23 03:24:01 2008|debug [24236]: Entering critical section : reading the header file Thu Oct 23 03:24:01 2008|debug [24236]: Exiting critical section Thu Oct 23 03:24:01 2008|debug [24236]: Header sent: HTTP/1.1 200 OK Hope this helps :) Cheers, --Seb -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]
