On Tue, 2008-03-25 at 17:51 +0000, Mark Hindley wrote:
> On Tue, Mar 25, 2008 at 10:17:51AM -0700, Ross Boylan wrote:
> > >
> > > Or am I missing your particular concern?
> > Apart from the error message, my main concern is that the cleanup isn't
> > working and it sounds as if the stuff in the cache is in a bad state
> > ("cached data may be damaged"). And I don't know how to fix it. So, my
> > questions are
> > 1) is apt-cacher safe to use for normal operations?
>
> Yes. Cleanup is not a requirement, just nice to prevent bloat.
>
> > 2) if safe, will it be current?
>
> Yes, apart from the index file that has failed to be refreshed
The failure seems to be on the main Packages file. Does that mean I
won't get updates to testing/main?
>
> > 3) how can I fix or diagnose the problem?
>
> The pipe command in sub get() in apt-cacher-cleanup.pl is failing.
>
> First I would try to get the url with wget, curl or someother browser.
> If that fails, then the problem is your upstream.
> If not, we will need to delve more deeply....
Seemed to work OK with lftp:
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
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)
It also worked with curl.
>
> 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.
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
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
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
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)
From
> 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.
>
> Mark
