On Wed, 2008-03-26 at 09:32 +0000, Mark Hindley wrote: > Thanks for this. There are some inconsistencies here with your upstream > server that (I think!) are causing the problem. > > > Seemed to work OK with lftp: > > This is not really relevant as it uses FTP. apt-cacher is HTTP only. > > > ???lftp ftp.us.debian.org:/debian/dists/testing/main/binary-i386> ls > > Package* > > -rw-rw-r-- 1 1001 1001 5025721 Mar 25 08:07 Packages.bz2 > > drwxrwsr-x 2 1001 1001 4096 Mar 25 08:32 Packages.diff > > -rw-rw-r-- 1 1001 1001 6578376 Mar 25 08:07 Packages.gz > > lftp ftp.us.debian.org:/debian/dists/testing/main/binary-i386> get > > Packages.bz2 > > 5025721 bytes transferred in 35 seconds (140.5K/s) > > lftp ftp.us.debian.org:/debian/dists/testing/main/binary-i386> > > cd ../source > > lftp ftp.us.debian.org:/debian/dists/testing/main/source> ls Sour* > > -rw-rw-r-- 1 1001 1001 1485002 Mar 25 08:21 Sources.bz2 Here's the file size on the server. > > drwxrwsr-x 2 1001 1001 4096 Mar 25 08:32 Sources.diff > > -rw-rw-r-- 1 1001 1001 2016422 Mar 25 08:21 Sources.gz > > lftp ftp.us.debian.org:/debian/dists/testing/main/source> get > > Sources.bz2 > > 1485002 bytes transferred in 10 seconds (142.0K/s) > > ^^^^^^^ Notice the size of Sources.bz2 > > > > It also worked with curl. > > Worked with curl using ftp or http? >From yesterday: $ curl http://ftp.us.debian.org/debian/dists/testing/main/source/Sources.bz2 > testSources.bz2 % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 1450k 100 1450k 0 0 130k 0 0:00:11 0:00:11 --:--:-- 178k
> > > > > > > There ought to be a libcurl error in the error.log which says what the > > > error was too. > > > > > There wasn't. Earlier today there was > > error.log only has > > Tue Mar 25 20:29:00 2008|info [22090]: Warning: no running inetd server > > found > > many times, with timestamps when apt-cacher or cleanup was active. > > Are you running apt-cacher from inetd or as a standalone daemon? If > standalone, this is just vebosity that I need to remove, but is > unrelated. Standalone, I think. /etc/default/apt-cacher has # set to 1 to start the daemon at boot time AUTOSTART=1 > > > I enabled debug in apt-cacher.conf and now see this: > > > > > > Tue Mar 25 20:37:27 2008|debug [22290]: Resolved request > > is /mainline/dists/testing/main/source/Sources.bz2 > > Tue Mar 25 20:37:27 2008|debug [22290]: new index file: > > mainline_dists_testing_main_source_Sources.bz2 > > Tue Mar 25 20:37:27 2008|debug [22290]: looking > > for > > /var/cache/apt-cacher/packages/mainline_dists_testing_main_source_Sources.bz2 > > Tue Mar 25 20:37:27 2008|debug [22290]: known as index file: Sources.bz2 > > Tue Mar 25 20:37:27 2008|debug [22290]: Init new libcurl object > > Tue Mar 25 20:37:27 2008|debug [22290]: Candidate: > > ftp.us.debian.org/debian > > Tue Mar 25 20:37:27 2008|debug [22290]: download agent: setting up for > > HEAD request > > Tue Mar 25 20:37:27 2008|debug [22290]: download agent: getting > > http://ftp.us.debian.org/debian/dists/testing/main/source/Sources.bz2 > > Tue Mar 25 20:37:27 2008|debug [22290]: libcurl download of headers > > complete > > Tue Mar 25 20:37:27 2008|debug [22290]: ETag headers different, > > "4488056-16adf5-8b938e80" <-> "4488052-16a8ca-a3d09b00". Refreshing > > cached file > > Tue Mar 25 20:37:27 2008|debug [22290]: EXPIRED > > Tue Mar 25 20:37:27 2008|debug [22290]: Entering critical section : file > > download decision > > Tue Mar 25 20:37:27 2008|debug [22290]: Waiting on another fetcher > > There is another process trying to get the file from your upstream another process spawned by my apt-cacher, or some other machine entirely? > > > Tue Mar 25 20:37:27 2008|debug [22290]: Exiting critical section > > Tue Mar 25 20:37:27 2008|debug [22290]: checks done, can return now > > Tue Mar 25 20:37:27 2008|debug [22290]: Entering critical section : > > reading the header file > > Tue Mar 25 20:37:27 2008|debug [22290]: Exiting critical section > > Tue Mar 25 20:37:27 2008|debug [22290]: Header sent: HTTP/1.1 200 OK > > Connection: Close > > Accept-Ranges: bytes > > ETag: "4488056-16adf5-8b938e80" > > Content-Length: 1486325 > > ^^^^^^^ Size is different > > Content-Type: text/plain > > Last-Modified: Mon, 24 Mar 2008 08:23:06 GMT > > > > Tue Mar 25 20:37:27 2008|debug [22290]: ready to send contents > > of > > /var/cache/apt-cacher/packages/mainline_dists_testing_main_source_Sources.bz2 > > # does "send contents of /var/cache...." sounds as if it got the file > > #but can't send it on > > Not necessarily as apt-cacher starts to deliver the file to a client > before it has recieved the whole file itself. > > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 65536) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 131072) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 196608) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 262144) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 327680) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 393216) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 458752) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 524288) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 589824) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 655360) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 720896) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 786432) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 851968) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 917504) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 983040) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 1048576) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 1114112) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 65536 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 65536 (sum: 1179648) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 12288 bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: wrote 12288 (sum: 1191936) bytes > > Tue Mar 25 20:37:27 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:37:28 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:37:29 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:37:30 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:37:31 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:37:32 2008|debug [22290]: read 0 bytes > > ## etc, many times > > Tue Mar 25 20:42:26 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:42:27 2008|debug [22290]: read 0 bytes > > Tue Mar 25 20:42:28 2008|debug [22290]: abort (timeout) > > Here is the error. The upstream failed to send the expected file size > within the timeout period. > > Could you > check the size of Sources.bz2 on the upstream server See the size listed from lftp at top of this report. > Try to get it with curl and http worked fine > Post the debug log which relates to the fetcher process for the file You mean more of the debug log above, or the debug log from curl? I don't know how to activate the latter. > (or send me all of it). It should look like (sample from my lerror.log): > > Wed Dec 5 00:10:43 2007|debug [5661]: file does not exist or download > forced, forking fetcher > Wed Dec 5 00:10:43 2007|debug [5665]: fetcher: try to fetch > http://security.debian.org/dists/stable/updates/main/binary-i386/Packages.gz > > and then everything related to ^^^^^^ this pid > > > > The ("cached data may be damaged") means that if the cleanup script > > > continues the cached files might be deleted prematurely rather than the > > > cache is damaged as it stands. > > "Cleanup aborted to prevent possible damage to cached data." > > might be clearer. > > Yes, I have already changed this in my tree. > > Mark -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]