I confirm that it is very fast downloading files (less than a second each), but when a file does not exist on the remote server, it takes at least one second per file. This results in about 1-2 minutes wasted. Certainly that is not huge in absolute terms, but in relative terms that is 96% overhead. That is horribly unnecessary and sloppy.
One problem appears to be a performance problem in the fetcher. The fetcher is very slow at figuring out that the file doesn't exist (which means the local [nonexistent] copy is up to date). The second problem is that there is no caching of the fact that the file does not exist. The check before fetching, to determine if a local copy matches the remote one, is fast (unless the documentation about expire_hours=0 is wrong and it is not actually comparing the fresh header). So one solution could be to not delete the /var/cache/apt- cacher/packages/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease file when there is a 404 error, and instead just cache the http header of the 404 error, and on next run, check to see if it is "updated" using the fresh HTTP headers (not trying to fetch again). ################################################# # Without apt-cacher ################################################# # time apt-get update Ign http://extras.ubuntu.com natty InRelease Ign http://security.ubuntu.com natty-security InRelease Ign http://archive.canonical.com natty InRelease Ign http://us.archive.ubuntu.com natty InRelease Ign http://us.archive.ubuntu.com natty-updates InRelease Hit http://extras.ubuntu.com natty Release.gpg Hit http://security.ubuntu.com natty-security Release.gpg Hit http://archive.canonical.com natty Release.gpg Hit http://us.archive.ubuntu.com natty Release.gpg Hit http://extras.ubuntu.com natty Release Hit http://us.archive.ubuntu.com natty-updates Release.gpg Hit http://security.ubuntu.com natty-security Release Hit http://archive.canonical.com natty Release Hit http://us.archive.ubuntu.com natty Release Hit http://us.archive.ubuntu.com natty-updates Release Hit http://extras.ubuntu.com natty/main Sources Hit http://security.ubuntu.com natty-security/main Sources Hit http://archive.canonical.com natty/partner Sources Hit http://us.archive.ubuntu.com natty/main Sources Hit http://us.archive.ubuntu.com natty/restricted Sources Hit http://us.archive.ubuntu.com natty/universe Sources Hit http://us.archive.ubuntu.com natty/multiverse Sources Hit http://us.archive.ubuntu.com natty/main amd64 Packages Ign http://download.virtualbox.org natty InRelease Hit http://extras.ubuntu.com natty/main amd64 Packages Ign http://extras.ubuntu.com natty/main TranslationIndex Hit http://security.ubuntu.com natty-security/restricted Sources Hit http://security.ubuntu.com natty-security/universe Sources Hit http://security.ubuntu.com natty-security/multiverse Sources Hit http://security.ubuntu.com natty-security/main amd64 Packages Hit http://security.ubuntu.com natty-security/restricted amd64 Packages Hit http://archive.canonical.com natty/partner amd64 Packages Ign http://archive.canonical.com natty/partner TranslationIndex Hit http://us.archive.ubuntu.com natty/restricted amd64 Packages Hit http://us.archive.ubuntu.com natty/universe amd64 Packages Hit http://us.archive.ubuntu.com natty/multiverse amd64 Packages Ign http://us.archive.ubuntu.com natty/main TranslationIndex Ign http://us.archive.ubuntu.com natty/multiverse TranslationIndex Ign http://us.archive.ubuntu.com natty/restricted TranslationIndex Ign http://us.archive.ubuntu.com natty/universe TranslationIndex Hit http://security.ubuntu.com natty-security/universe amd64 Packages Hit http://security.ubuntu.com natty-security/multiverse amd64 Packages Ign http://security.ubuntu.com natty-security/main TranslationIndex Ign http://security.ubuntu.com natty-security/multiverse TranslationIndex Ign http://security.ubuntu.com natty-security/restricted TranslationIndex Ign http://security.ubuntu.com natty-security/universe TranslationIndex Hit http://us.archive.ubuntu.com natty-updates/main Sources Hit http://us.archive.ubuntu.com natty-updates/restricted Sources Hit http://us.archive.ubuntu.com natty-updates/universe Sources Hit http://us.archive.ubuntu.com natty-updates/multiverse Sources Hit http://us.archive.ubuntu.com natty-updates/main amd64 Packages Hit http://us.archive.ubuntu.com natty-updates/restricted amd64 Packages Hit http://us.archive.ubuntu.com natty-updates/universe amd64 Packages Hit http://us.archive.ubuntu.com natty-updates/multiverse amd64 Packages Ign http://us.archive.ubuntu.com natty-updates/main TranslationIndex Ign http://us.archive.ubuntu.com natty-updates/multiverse TranslationIndex Ign http://us.archive.ubuntu.com natty-updates/restricted TranslationIndex Ign http://us.archive.ubuntu.com natty-updates/universe TranslationIndex Hit http://download.virtualbox.org natty Release.gpg Ign http://extras.ubuntu.com natty/main Translation-en_US Ign http://archive.canonical.com natty/partner Translation-en_US Hit http://download.virtualbox.org natty Release Ign http://extras.ubuntu.com natty/main Translation-en Ign http://archive.canonical.com natty/partner Translation-en Ign http://us.archive.ubuntu.com natty/main Translation-en_US Ign http://us.archive.ubuntu.com natty/main Translation-en Ign http://us.archive.ubuntu.com natty/multiverse Translation-en_US Ign http://us.archive.ubuntu.com natty/multiverse Translation-en Ign http://us.archive.ubuntu.com natty/restricted Translation-en_US Ign http://us.archive.ubuntu.com natty/restricted Translation-en Ign http://us.archive.ubuntu.com natty/universe Translation-en_US Ign http://us.archive.ubuntu.com natty/universe Translation-en Ign http://us.archive.ubuntu.com natty-updates/main Translation-en_US Ign http://us.archive.ubuntu.com natty-updates/main Translation-en Ign http://us.archive.ubuntu.com natty-updates/multiverse Translation-en_US Ign http://security.ubuntu.com natty-security/main Translation-en_US Ign http://us.archive.ubuntu.com natty-updates/multiverse Translation-en Ign http://us.archive.ubuntu.com natty-updates/restricted Translation-en_US Ign http://us.archive.ubuntu.com natty-updates/restricted Translation-en Ign http://security.ubuntu.com natty-security/main Translation-en Ign http://security.ubuntu.com natty-security/multiverse Translation-en_US Ign http://security.ubuntu.com natty-security/multiverse Translation-en Ign http://security.ubuntu.com natty-security/restricted Translation-en_US Ign http://us.archive.ubuntu.com natty-updates/universe Translation-en_US Ign http://us.archive.ubuntu.com natty-updates/universe Translation-en Ign http://security.ubuntu.com natty-security/restricted Translation-en Ign http://security.ubuntu.com natty-security/universe Translation-en_US Ign http://security.ubuntu.com natty-security/universe Translation-en Hit http://download.virtualbox.org natty/contrib amd64 Packages Ign http://download.virtualbox.org natty/contrib TranslationIndex Ign http://download.virtualbox.org natty/contrib Translation-en_US Ign http://download.virtualbox.org natty/contrib Translation-en Reading package lists... Done real 0m2.341s user 0m0.040s sys 0m0.010s ################################################# # With apt-cacher ################################################# # Creates a nice ugly timer on the right side of the text while running the test runtest() { touch runenabled; while [ -e runenabled ]; do echo -n " "$(date) sleep 1 done & time apt-get update rm runenabled } runtest Ign http://aptproxy.bc.local natty InRelease Fri Nov 18 16:21:21 CET 2011 Ign http://aptproxy.bc.local natty-updates InRelease Fri Nov 18 16:21:22 CET 2011 Ign http://aptproxy.bc.local natty-security InRelease Ign http://aptproxy.bc.local natty InRelease Fri Nov 18 16:21:23 CET 2011 Ign http://aptproxy.bc.local natty InRelease Fri Nov 18 16:21:24 CET 2011 Ign http://aptproxy.bc.local natty InRelease Fri Nov 18 16:21:25 CET 2011 Hit http://aptproxy.bc.local natty Release.gpg Hit http://aptproxy.bc.local natty-updates Release.gpg Hit http://aptproxy.bc.local natty-security Release.gpg Hit http://aptproxy.bc.local natty Release.gpg Hit http://aptproxy.bc.local natty Release.gpg Hit http://aptproxy.bc.local natty Release.gpg Hit http://aptproxy.bc.local natty Release Hit http://aptproxy.bc.local natty-updates Release Hit http://aptproxy.bc.local natty-security Release Hit http://aptproxy.bc.local natty Release Hit http://aptproxy.bc.local natty Release Hit http://aptproxy.bc.local natty Release Fri Nov 18 16:21:26 CET 2011 Hit http://aptproxy.bc.local natty/main Sources Hit http://aptproxy.bc.local natty/restricted Sources Hit http://aptproxy.bc.local natty/universe Sources Hit http://aptproxy.bc.local natty/multiverse Sources Hit http://aptproxy.bc.local natty/main amd64 Packages Hit http://aptproxy.bc.local natty/restricted amd64 Packages Hit http://aptproxy.bc.local natty/universe amd64 Packages Hit http://aptproxy.bc.local natty/multiverse amd64 Packages Ign http://aptproxy.bc.local natty/main TranslationIndex Fri Nov 18 16:21:27 CET 2011 Ign http://aptproxy.bc.local natty/multiverse TranslationIndexri Nov 18 16:21:28 CET 2011 Ign http://aptproxy.bc.local natty/restricted TranslationIndexri Nov 18 16:21:29 CET 2011 Ign http://aptproxy.bc.local natty/universe TranslationIndex Fri Nov 18 16:21:30 CET 2011 Hit http://aptproxy.bc.local natty-updates/main Sources Hit http://aptproxy.bc.local natty-updates/restricted Sources Hit http://aptproxy.bc.local natty-updates/universe Sources Hit http://aptproxy.bc.local natty-updates/multiverse Sources Hit http://aptproxy.bc.local natty-updates/main amd64 Packages Hit http://aptproxy.bc.local natty-updates/restricted amd64 Packages Hit http://aptproxy.bc.local natty-updates/universe amd64 Packages Hit http://aptproxy.bc.local natty-updates/multiverse amd64 Packages Ign http://aptproxy.bc.local natty-updates/main TranslationIndex Nov 18 16:21:31 CET 2011 Ign http://aptproxy.bc.local natty-updates/multiverse TranslationIndex8 16:21:32 CET 2011 Ign http://aptproxy.bc.local natty-updates/restricted TranslationIndex8 16:21:33 CET 2011 Ign http://aptproxy.bc.local natty-updates/universe TranslationIndex 18 16:21:34 CET 2011 Hit http://aptproxy.bc.local natty-security/main Sources Hit http://aptproxy.bc.local natty-security/restricted Sources Hit http://aptproxy.bc.local natty-security/universe Sources Hit http://aptproxy.bc.local natty-security/multiverse Sources Hit http://aptproxy.bc.local natty-security/main amd64 Packages Hit http://aptproxy.bc.local natty-security/restricted amd64 Packages Hit http://aptproxy.bc.local natty-security/universe amd64 Packages Hit http://aptproxy.bc.local natty-security/multiverse amd64 Packages Ign http://aptproxy.bc.local natty-security/main TranslationIndexNov 18 16:21:35 CET 2011 Ign http://aptproxy.bc.local natty-security/multiverse TranslationIndex 16:21:36 CET 2011 Ign http://aptproxy.bc.local natty-security/restricted TranslationIndex 16:21:37 CET 2011 Ign http://aptproxy.bc.local natty-security/universe TranslationIndex18 16:21:38 CET 2011 Hit http://aptproxy.bc.local natty/partner Sources Hit http://aptproxy.bc.local natty/partner amd64 Packages Ign http://aptproxy.bc.local natty/partner TranslationIndex Fri Nov 18 16:21:39 CET 2011 Hit http://aptproxy.bc.local natty/main Sources Hit http://aptproxy.bc.local natty/main amd64 Packages Ign http://aptproxy.bc.local natty/main TranslationIndex Fri Nov 18 16:21:40 CET 2011 Hit http://aptproxy.bc.local natty/contrib amd64 Packages Ign http://aptproxy.bc.local natty/contrib TranslationIndex Fri Nov 18 16:21:41 CET 2011 Ign http://aptproxy.bc.local natty/main Translation-en_US Fri Nov 18 16:22:12 CET 2011 Ign http://aptproxy.bc.local natty/main Translation-en Ign http://aptproxy.bc.local natty/multiverse Translation-en_US Ign http://aptproxy.bc.local natty/multiverse Translation-en Ign http://aptproxy.bc.local natty/restricted Translation-en_US Ign http://aptproxy.bc.local natty/restricted Translation-en Ign http://aptproxy.bc.local natty/universe Translation-en_US Ign http://aptproxy.bc.local natty/universe Translation-en Ign http://aptproxy.bc.local natty-updates/main Translation-en_US Ign http://aptproxy.bc.local natty-updates/main Translation-en Ign http://aptproxy.bc.local natty-updates/multiverse Translation-en_US Ign http://aptproxy.bc.local natty-updates/multiverse Translation-en Ign http://aptproxy.bc.local natty-updates/restricted Translation-en_US Ign http://aptproxy.bc.local natty-updates/restricted Translation-en Ign http://aptproxy.bc.local natty-updates/universe Translation-en_US Ign http://aptproxy.bc.local natty-updates/universe Translation-en Ign http://aptproxy.bc.local natty-security/main Translation-en_US Ign http://aptproxy.bc.local natty-security/main Translation-en Ign http://aptproxy.bc.local natty-security/multiverse Translation-en_US Ign http://aptproxy.bc.local natty-security/multiverse Translation-en Ign http://aptproxy.bc.local natty-security/restricted Translation-en_US Ign http://aptproxy.bc.local natty-security/restricted Translation-en Ign http://aptproxy.bc.local natty-security/universe Translation-en_US Ign http://aptproxy.bc.local natty-security/universe Translation-en Ign http://aptproxy.bc.local natty/partner Translation-en_US Ign http://aptproxy.bc.local natty/partner Translation-en Ign http://aptproxy.bc.local natty/main Translation-en_US Ign http://aptproxy.bc.local natty/main Translation-en Ign http://aptproxy.bc.local natty/contrib Translation-en_US Ign http://aptproxy.bc.local natty/contrib Translation-en Reading package lists... Done real 0m52.964s user 0m0.060s sys 0m0.020s ################################################# /var/log/apt-cacher/error.log with debug mode enabled ################################################# Entire first request: Fri Nov 18 16:27:53 2011|debug [24743]: Connection from 10.3.0.26 Fri Nov 18 16:27:53 2011|debug [24743]: registered child process: 25364 Fri Nov 18 16:27:53 2011|debug [25364]: New Daemon connection Fri Nov 18 16:27:53 2011|debug [25364]: Processing a new request line Fri Nov 18 16:27:53 2011|debug [25364]: got: GET /de.archive.ubuntu.com/ubuntu/dists/natty/InRelease HTTP/1.1 Fri Nov 18 16:27:53 2011|debug [25364]: Processing a new request line Fri Nov 18 16:27:53 2011|debug [25364]: got: Host: aptproxy.bc.local:3142 Fri Nov 18 16:27:53 2011|debug [25364]: Processing a new request line Fri Nov 18 16:27:53 2011|debug [25364]: got: Connection: keep-alive Fri Nov 18 16:27:53 2011|debug [25364]: Processing a new request line Fri Nov 18 16:27:53 2011|debug [25364]: got: Cache-Control: max-age=0 Fri Nov 18 16:27:53 2011|debug [25364]: Request specified Cache-Control: max-age=0 Fri Nov 18 16:27:53 2011|debug [25364]: Processing a new request line Fri Nov 18 16:27:53 2011|debug [25364]: got: User-Agent: Debian APT-HTTP/1.3 (0.8.13.2ubuntu4.2) Fri Nov 18 16:27:53 2011|debug [25364]: Processing a new request line Fri Nov 18 16:27:53 2011|debug [25364]: got: Fri Nov 18 16:27:53 2011|debug [25364]: Resolved request is /de.archive.ubuntu.com/ubuntu/dists/natty/InRelease Fri Nov 18 16:27:53 2011|debug [25364]: new index file: de.archive.ubuntu.com_ubuntu_dists_natty_InRelease Fri Nov 18 16:27:53 2011|debug [25364]: looking for /var/cache/apt-cacher/packages/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease Fri Nov 18 16:27:53 2011|debug [25364]: known as index file: InRelease Fri Nov 18 16:27:53 2011|debug [25364]: Entering critical section : file download decision Fri Nov 18 16:27:53 2011|debug [25364]: file does not exist or download required, forking fetcher Fri Nov 18 16:27:53 2011|debug [25364]: MISS Fri Nov 18 16:27:53 2011|debug [25364]: registered child process: 25365 Fri Nov 18 16:27:53 2011|debug [25364]: checks done, can return now Fri Nov 18 16:27:53 2011|debug [25365]: Exiting critical section Fri Nov 18 16:27:53 2011|debug [25365]: fetcher: try to fetch http://de.archive.ubuntu.com/ubuntu/dists/natty/InRelease Fri Nov 18 16:27:53 2011|debug [25365]: download agent: getting http://de.archive.ubuntu.com/ubuntu/dists/natty/InRelease Fri Nov 18 16:27:53 2011|debug [25365]: Sending libcurl http://de.archive.ubuntu.com/ubuntu/dists/natty/InRelease Fri Nov 18 16:27:53 2011|debug [25365]: Entering critical section : connect libcurl Fri Nov 18 16:27:53 2011|debug [25366]: Init libcurl thread Fri Nov 18 16:27:53 2011|debug [25365]: Waiting for libcurl socket Fri Nov 18 16:27:53 2011|debug [25366]: Exiting critical section Fri Nov 18 16:27:54 2011|debug [25365]: Connection to new libcurl process on /var/cache/apt-cacher/libcurl.socket Fri Nov 18 16:27:54 2011|debug [25366]: libcurl: connection from IO::Socket::UNIX=GLOB(0x23ae3d8) Fri Nov 18 16:27:54 2011|debug [25366]: Libcurl: thawed request http://de.archive.ubuntu.com/ubuntu/dists/natty/InRelease, , Cache-Control: max-age=0 Fri Nov 18 16:27:54 2011|debug [25366]: Init new libcurl object Fri Nov 18 16:27:54 2011|debug [25366]: Add curl handle #1: for http://de.archive.ubuntu.com/ubuntu/dists/natty/InRelease Fri Nov 18 16:27:54 2011|debug [25366]: libcurl: setting up for GET request Fri Nov 18 16:27:55 2011|debug CURLINFO_TEXT [25366]: About to connect() to de.archive.ubuntu.com port 80 (#0) Fri Nov 18 16:27:55 2011|debug CURLINFO_TEXT [25366]: Trying 141.30.13.10... Fri Nov 18 16:27:55 2011|debug CURLINFO_TEXT [25366]: Connected to de.archive.ubuntu.com (141.30.13.10) port 80 (#0) Fri Nov 18 16:27:55 2011|debug CURLINFO_TEXT [25366]: Expire cleared Fri Nov 18 16:27:55 2011|debug CURLINFO_TEXT [25366]: Connection #0 to host de.archive.ubuntu.com left intact Fri Nov 18 16:27:55 2011|debug [25366]: curl handle #1 completed, status: 0 Fri Nov 18 16:27:55 2011|debug [25365]: libcurl reading of headers complete Fri Nov 18 16:27:55 2011|debug [25366]: libcurl active transfers: 0 Fri Nov 18 16:27:55 2011|debug [25365]: Entering critical section : libcurl, storing the header to /var/cache/apt-cacher/headers/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease Fri Nov 18 16:27:55 2011|debug [25365]: Writing header Fri Nov 18 16:27:55 2011|debug [25365]: Exiting critical section Fri Nov 18 16:27:55 2011|debug [25365]: Found EOF marker and status FrT;@2|$1|0$0| Fri Nov 18 16:27:55 2011|debug [25365]: libcurl returned Fri Nov 18 16:27:55 2011|debug [25365]: Got error 404 for http://de.archive.ubuntu.com/ubuntu/dists/natty/InRelease. Deleting /var/cache/apt-cacher/packages/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease. Fri Nov 18 16:27:55 2011|debug [25365]: fetcher done Fri Nov 18 16:27:55 2011|debug [25365]: Clean up before exiting. Fri Nov 18 16:27:55 2011|debug [25364]: Entering critical section : reading the header file Fri Nov 18 16:27:55 2011|debug [25364]: Exiting critical section Fri Nov 18 16:27:55 2011|debug [25364]: Header sent: HTTP/1.1 404 Not Found Connection: Keep-Alive Content-Length: 0 Fri Nov 18 16:27:55 2011|debug [25364]: Package sent # cat /var/cache/apt-cacher/headers/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease HTTP/1.1 404 Not Found Connection: keep-alive Date: Fri, 18 Nov 2011 15:27:55 GMT Age: 0 Server: ATS/2.1.5-unstable Vary: Accept-Encoding Content-Length: 313 Content-Type: text/html; charset=iso-8859-1 # cat /var/cache/apt-cacher/packages/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease cat: /var/cache/apt-cacher/packages/de.archive.ubuntu.com_ubuntu_dists_natty_InRelease: No such file or directory -- You received this bug notification because you are a member of Ubuntu Bugs, which is subscribed to Ubuntu. https://bugs.launchpad.net/bugs/602732 Title: apt-get update through apt-cacher is unreasonably slow To manage notifications about this bug go to: https://bugs.launchpad.net/ubuntu/+source/apt-cacher/+bug/602732/+subscriptions -- ubuntu-bugs mailing list [email protected] https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs
