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]

Reply via email to