Bug 91609

Summary: refresh-cache with apt backend fails with "Packages is not (yet) available ()"
Product: PackageKit Reporter: Sunil Mohan Adapa <sunil>
Component: backend-aptAssignee: Richard Hughes <richard>
Status: RESOLVED NOTABUG QA Contact:
Severity: major    
Priority: medium    
Version: unspecified   
Hardware: Other   
OS: All   
Whiteboard:
i915 platform: i915 features:

Description Sunil Mohan Adapa 2015-08-11 18:02:44 UTC 
When Packages list is being downloaded, apt has a mechanism to try one type of compression before trying another.  It may fail with the first and succeed with the later in an operation that is in the end considered successful.  In this scenario packagekit refresh-cache always fails.

======
Error I receive from application (Plinth, web UI for FreedomBox).

E: http://ftp.us.debian.org sid/main armhf Packages is not (yet) available () 

======
Apt-get update showing a failed Packages retrieval attempt but ultimately succeeding.

root@freedombox:/etc/apt/apt.conf.d# apt-get update
Hit http://ftp.us.debian.org sid InRelease
Get:1 http://ftp.us.debian.org sid/main Sources/DiffIndex [7876 B]
Get:2 http://ftp.us.debian.org sid/main armhf Packages/DiffIndex [7876 B]
Get:3 http://ftp.us.debian.org sid/main Translation-en/DiffIndex [7876 B]
Err http://ftp.us.debian.org sid/main armhf Packages

Hit http://ftp.us.debian.org sid/main armhf Packages
Fetched 23.6 kB in 19s (1237 B/s)
Reading package lists... Done
root@freedombox:/etc/apt/apt.conf.d# echo $?
0

======
Debug information of apt showing that request is made to Packages.bz2 first and then Packages.xz

# apt-get -o Debug::Acquire::http=true update

...

ET /debian/dists/sid/main/binary-armhf/Packages.bz2 HTTP/1.1
Host: ftp.us.debian.org
Cache-Control: max-age=0
If-Modified-Since: Tue, 11 Aug 2015 14:17:11 GMT
User-Agent: Debian APT-HTTP/1.3 (1.0.10.1)


Answer for: http://ftp.us.debian.org/debian/dists/sid/main/binary-armhf/Packages.bz2
HTTP/1.1 404 Not Found
Date: Tue, 11 Aug 2015 17:12:58 GMT
Server: Apache
Content-Length: 312
Content-Type: text/html; charset=iso-8859-1

Err http://ftp.us.debian.org sid/main armhf Packages
GET /debian/dists/sid/main/binary-armhf/Packages.xz HTTP/1.1
Host: ftp.us.debian.org
Cache-Control: max-age=0
If-Modified-Since: Tue, 11 Aug 2015 14:17:11 GMT
User-Agent: Debian APT-HTTP/1.3 (1.0.10.1)


Answer for: http://ftp.us.debian.org/debian/dists/sid/main/binary-armhf/Packages.xz
HTTP/1.1 304 Not Modified
Date: Tue, 11 Aug 2015 17:12:58 GMT
Server: Apache
ETag: "70cf50-51d09c20b87c0"

...

=======
As a work around if I set the following in apt configuration, the problem is fixed.

Acquire::CompressionTypes::Order:: "xz";

=======
packagekitd --verbose

17:55:38        PackageKit      Verbose debugging enabled (on console 0)
17:55:38        PackageKit      daemon shutdown set to 0 seconds
17:55:38        PackageKit      clearing download cache at /var/cache/PackageKit/downloads
17:55:39        PackageKit      destination eth1 is valid
17:55:39        PackageKit      setting config file watch on /etc/PackageKit/PackageKit.conf
17:55:39        PackageKit      Trying to load : aptcc
17:55:39        PackageKit      dlopening '/usr/lib/arm-linux-gnueabihf/packagekit-backend/libpk_backend_aptcc.so'
17:55:39        PackageKit      trying to open database '/var/lib/PackageKit/transactions.db'
17:55:39        PackageKit      job count is now at 111
17:55:39        PackageKit      is_default: 1
17:55:39        PackageKit      network state is wired
17:55:39        PackageKit      PkEngine: acquired name: org.freedesktop.PackageKit
17:55:44        PackageKit      CreateTransaction method called
17:55:44        PackageKit      job count now 112
17:55:44        PackageKit      trying to open database '/var/lib/PackageKit/transactions.db'
17:55:44        PackageKit      job count is now at 111
17:55:44        PackageKit      transaction now new
17:55:44        PackageKit      setting sender to :1.114
17:55:44        PackageKit      adding transaction 0xb83a10e0
17:55:44        PackageKit      sending object path: '/112_aacacbad'
17:55:44        PackageKit      notify::connected
17:55:47        PackageKit      SetHints method called: locale=C, background=false, interactive=true, cache-age=4294967295
17:55:47        PackageKit      cache-age changed to -1
17:55:47        PackageKit      Resolve method called: 2, ikiwiki&gcc&libc6-dev&libtimedate-perl&libcgi-formbuilder-perl&libcgi-session-perl&libxml-writer-perl
17:55:47        PackageKit      transaction now ready
17:55:47        PackageKit      changing transaction to exclusive mode
17:55:47        PackageKit      1 transactions in list, 1 committed but not finished
17:55:47        PackageKit      transaction now running
***
17:55:47        PackageKit      failed to get session, errno -6
***
17:55:47        PackageKit      failed to set the session state (non-fatal): failed to get the session
17:55:47        PackageKit      setting role for /112_aacacbad to resolve
17:55:48        PackageKit      State:
0       resolve /112_aacacbad   state[running] exclusive[1] background[0]

17:55:48        PackageKit      1 are running
***
17:55:49        PackageKit      percentage value is going down to 0 from 78
***
***
17:55:49        PackageKit      percentage value is going down to 0 from 78
***
17:55:49        PackageKit      emit package installed, gcc;4:5.2.1-4;armhf;unstable, GNU C compiler
17:55:49        PackageKit      emit package available, ikiwiki;3.20150614;all;unstable, a wiki compiler
17:55:49        PackageKit      emit package installed, libc6-dev;2.19-19;armhf;unstable, GNU C Library: Development Libraries and Header Files
17:55:49        PackageKit      emit package available, libcgi-formbuilder-perl;3.09-3;all;unstable, Easily generate and process stateful CGI forms
17:55:49        PackageKit      emit package available, libcgi-session-perl;4.48-2;all;unstable, persistent session data in CGI applications
17:55:49        PackageKit      emit package installed, libtimedate-perl;2.3000-2;all;unstable, collection of modules to manipulate date/time information
17:55:49        PackageKit      emit package available, libxml-writer-perl;0.625-1;all;unstable, Perl module for writing XML documents
17:55:49        PackageKit      backend was running for 1506 ms
17:55:49        PackageKit      emitting finished 'success', 1506
17:55:49        PackageKit      transaction now finished
17:55:49        PackageKit      1 transactions in list, 0 committed but not finished
17:55:49        PackageKit      CreateTransaction method called
17:55:49        PackageKit      job count now 113
17:55:49        PackageKit      trying to open database '/var/lib/PackageKit/transactions.db'
17:55:49        PackageKit      job count is now at 112
17:55:49        PackageKit      transaction now new
17:55:49        PackageKit      setting sender to :1.114
17:55:49        PackageKit      adding transaction 0xb83a11d0
17:55:49        PackageKit      sending object path: '/113_acbcadca'
17:55:50        PackageKit      SetHints method called: locale=C, background=false, interactive=false, cache-age=4294967295
17:55:50        PackageKit      cache-age changed to -1
17:55:50        PackageKit      RefreshCache method called: 0
17:55:50        PackageKit      transaction now waiting-for-auth
17:55:50        PackageKit      authorizing action org.freedesktop.packagekit.system-sources-refresh
17:55:50        PackageKit      transaction now ready
17:55:50        PackageKit      changing transaction to exclusive mode
17:55:50        PackageKit      2 transactions in list, 1 committed but not finished
17:55:50        PackageKit      transaction now running
***
17:55:50        PackageKit      failed to get session, errno -6
***
17:55:50        PackageKit      failed to set the session state (non-fatal): failed to get the session
17:55:50        PackageKit      setting role for /113_acbcadca to refresh-cache
***
17:55:51        PackageKit      percentage value is going down to 0 from 75
***
***
17:55:51        PackageKit      percentage value is going down to 0 from 75
***
17:55:52        PackageKit      is_default: 1
17:55:52        PackageKit      network state is wired
17:55:52        PackageKit      emitting repo-detail , http://ftp.us.debian.org sid InRelease, 1
17:55:54        PackageKit      transaction /112_aacacbad completed, removing
17:55:54        PackageKit      emitting destroy /112_aacacbad
17:55:58        PackageKit      State:
0       refresh-cache   /113_acbcadca   state[running] exclusive[1] background[0]

17:55:58        PackageKit      1 are running
17:56:00        PackageKit      emitting error-code cannot-fetch-sources, 'E: http://ftp.us.debian.org sid/main armhf Packages is not (yet) available ()
'
17:56:00        PackageKit      backend was running for 10134 ms
17:56:00        PackageKit      emitting finished 'failed', 10134
17:56:00        PackageKit      transaction now finished
17:56:00        PackageKit      1 transactions in list, 0 committed but not finished
17:56:05        PackageKit      transaction /113_acbcadca completed, removing
17:56:05        PackageKit      emitting destroy /113_acbcadca
17:56:06        PackageKit      Handling SIGINT

======
Version of packagekit (installed from stock Debian unstable)

root@freedombox:/etc/apt/apt.conf.d# /usr/lib/packagekit/packagekitd --version
Version 1.0.6

======
Version of Debian package

ii  packagekit                                      1.0.6-1+b1                   armhf                        Provides a package management service

======
Debian version (with custom kernel)

root@freedombox:/etc/apt/apt.conf.d# uname -a
Linux freedombox 3.18.0+ #10 SMP Mon Mar 23 22:44:25 IST 2015 armv7l GNU/Linux
root@freedombox:/etc/apt/apt.conf.d# lsb_release -a
No LSB modules are available.
Distributor ID:	Debian
Description:	Debian GNU/Linux unstable (sid)
Release:	unstable
Codename:	sid
Comment 1 Sunil Mohan Adapa 2015-09-04 09:20:07 UTC 
On #debian-apt IRC channel, I got a hint about the nature of the problem and possible fix.

=== Quote ===
<DonKult> sunilmohan: sorry, no idea about PackageKit, but that looks like it uses the pkgAcquireStatus::Fail method – which is where the Err line comes from in apt-get – and decides based on that if the whole operation failed, while what actually should be done is asking the Fetcher at the end for all items and check if any of them was a failure as even if the download of an item fails, libapt can potentially recover and still get the item successfully some other way.
=== End quote ===
Comment 2 Richard Hughes 2018-08-21 15:52:32 UTC 
We moved the upstream bugtracker to GitHub a long time ago. If this issue still affects you please re-create the issue here: https://github.com/hughsie/PackageKit/issues
 
Sorry for the impersonal message, and fingers crossed your issue no longer happens. Thanks.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.