Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1685037 - PackageKit crashes in getActive on g_str_hash
Summary: PackageKit crashes in getActive on g_str_hash
Keywords:
Status: VERIFIED
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: subscription-manager
Version: 8.0
Hardware: Unspecified
OS: Unspecified
urgent
unspecified
Target Milestone: rc
: 8.0
Assignee: candlepin-bugs
QA Contact: Red Hat subscription-manager QE Team
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-03-04 08:40 UTC by Matej Marušák
Modified: 2019-03-11 08:05 UTC (History)
5 users (show)

Fixed In Version: subscription-manager-1.23.8-35
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:
Type: Bug
Target Upstream Version:


Attachments (Terms of Use)
journal log (deleted)
2019-03-04 08:40 UTC, Matej Marušák
no flags Details
backtrace (deleted)
2019-03-04 08:40 UTC, Matej Marušák
no flags Details
reproducer script (deleted)
2019-03-05 09:15 UTC, Martin Pitt
no flags Details


Links
System ID Priority Status Summary Last Updated
Github candlepin subscription-manager pull 2048 None None None 2019-03-05 19:32:04 UTC

Description Matej Marušák 2019-03-04 08:40:13 UTC
Created attachment 1540548 [details]
journal log

Description of problem:
PackageKit crashes in getActive on g_str_hash
Stacktrace:

Stack trace of thread 3624:                                                     
#0  0x00007f1eee2c89f4 g_str_hash (libglib-2.0.so.0)                            
#1  0x00007f1eee2c81f8 g_hash_table_lookup_node (libglib-2.0.so.0)              
#2  0x00007f1ec7c21c7e getActive (product-id.so)                                
#3  0x00007f1ec7c22996 pluginHook (product-id.so)                               
#4  0x00007f1ed7383a03 _ZN6libdnf7Plugins4hookE12PluginHookIdPNS_14PluginHookDataEPNS_11PluginErrorE (libdnf.so.2)
#5  0x00007f1ed72dc4dc dnf_transaction_commit (libdnf.so.2)                     
#6  0x00007f1edc2fed9c pk_backend_transaction_download_commit (libpk_backend_dnf.so)
#7  0x00007f1edc300d68 pk_backend_update_packages_thread (libpk_backend_dnf.so) 
#8  0x000055cab3fa1abe pk_backend_job_thread_setup (packagekitd)                
#9  0x00007f1eee301f9a g_thread_proxy (libglib-2.0.so.0)                        
#10 0x00007f1eedbb92de start_thread (libpthread.so.0)                           
#11 0x00007f1eed8e9a63 __clone (libc.so.6)                                      
                                                                                
Stack trace of thread 1828:                                                     
#0  0x00007f1eed8de7e1 __GI___poll (libc.so.6)                                  
#1  0x00007f1eee2d9bd6 g_main_context_poll (libglib-2.0.so.0)                   
#2  0x00007f1eee2d9f92 g_main_loop_run (libglib-2.0.so.0)                       
#3  0x000055cab3f8c629 main (packagekitd)                                       
#4  0x00007f1eed810813 __libc_start_main (libc.so.6)                            
#5  0x000055cab3f8c8de _start (packagekitd)                                     
                                                                                
Stack trace of thread 1831:                                                     
#0  0x00007f1eed8de7e1 __GI___poll (libc.so.6)                                  
#1  0x00007f1eee2d9bd6 g_main_context_poll (libglib-2.0.so.0)                   
#2  0x00007f1eee2d9d00 g_main_context_iteration (libglib-2.0.so.0)              
#3  0x00007f1eee2d9d51 glib_worker_main (libglib-2.0.so.0)                      
#4  0x00007f1eee301f9a g_thread_proxy (libglib-2.0.so.0)                        
#5  0x00007f1eedbb92de start_thread (libpthread.so.0)                           
#6  0x00007f1eed8e9a63 __clone (libc.so.6)                                      
                                                                                
Stack trace of thread 1832:                                                     
#0  0x00007f1eed8de7e1 __GI___poll (libc.so.6)                                  
#1  0x00007f1eee2d9bd6 g_main_context_poll (libglib-2.0.so.0)                   
#2  0x00007f1eee2d9f92 g_main_loop_run (libglib-2.0.so.0)                       
#3  0x00007f1eee8ca8aa gdbus_shared_thread_func (libgio-2.0.so.0)               
#4  0x00007f1eee301f9a g_thread_proxy (libglib-2.0.so.0)                        
#5  0x00007f1eedbb92de start_thread (libpthread.so.0)                           
#6  0x00007f1eed8e9a63 __clone (libc.so.6)                                      
                                                                                
Stack trace of thread 1833:                                                     
#0  0x00007f1eed8e42bd syscall (libc.so.6)                                      
#1  0x00007f1eee320cfe g_cond_wait_until (libglib-2.0.so.0)                     
#2  0x00007f1eee2ac0f1 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)     
#3  0x00007f1eee2ac6e0 g_async_queue_timeout_pop (libglib-2.0.so.0)             
#4  0x00007f1eee302a41 g_thread_pool_wait_for_new_pool (libglib-2.0.so.0)       
#5  0x00007f1eee301f9a g_thread_proxy (libglib-2.0.so.0)                        
#6  0x00007f1eedbb92de start_thread (libpthread.so.0)                           
#7  0x00007f1eed8e9a63 __clone (libc.so.6) 


Version-Release number of selected component (if applicable):
PackageKit-1.1.12-2.el8.x86_64
libdnf-0.22.5-4.el8.x86_64

How reproducible:
This is reported as cockpit tests fail, see https://github.com/cockpit-project/cockpit/pull/11288
Even though it crashes on install in our tests, I can easily reproduce it with removal of package.

Steps to Reproduce:
1. pkcon install abrt
2. pkcon remove abrt <- this dumps core

Actual results:
PackageKit dumps core

Expected results:
PackageKit does not dump core and finishes transaction successfully


Additional info:
Crashed thread (all threads in attachment)

Thread 1 (Thread 0x7f1ec6cbb700 (LWP 3624)):
#0  g_str_hash (v=0x0) at ghash.c:1894
        p = 0x0
        h = 5381
#1  0x00007f1eee2c81f8 in g_hash_table_lookup_node (hash_return=<synthetic pointer>, key=0x0, 
    hash_table=0x55cab5c21aa0) at ghash.c:379
        node_hash = <optimized out>
        hash_value = <optimized out>
        have_tombstone = 0
        step = 0
        node_index = <optimized out>
        first_tombstone = 0
        node_index = <optimized out>
        node_hash = <optimized out>
        hash_value = <optimized out>
        first_tombstone = <optimized out>
        have_tombstone = <optimized out>
        step = <optimized out>
        __func__ = "g_hash_table_lookup_node"
        _g_boolean_var_ = <optimized out>
        _g_boolean_var_ = <optimized out>
        node_key = <optimized out>
#2  g_hash_table_contains (hash_table=hash_table@entry=0x55cab5c21aa0, key=key@entry=0x0) at ghash.c:1343
        node_index = <optimized out>
        node_hash = <optimized out>
        __func__ = "g_hash_table_contains"
#3  0x00007f1ec7c21c7e in getActive (dnfContext=0x55cab5bd2130, hookData=<optimized out>, 
    enabledRepoAndProductIds=0x55cab5b20400, activeRepoAndProductIds=0x7f1ed8002320)
    at /usr/src/debug/subscription-manager-1.23.8-33.el8.x86_64/src/dnf-plugins/product-id/product-id.c:637
        instPkg = <optimized out>
        repo_name = 0x0
        k = 68
        activeRepos = 0x55cab5c21aa0
        transaction = <optimized out>
        db = <optimized out>
        goal = <optimized out>
        dnfSack = <optimized out>
        rpmDbSack = 0x55cab5c66680
        installedPackages = 0x55cab5d22460
#4  0x00007f1ec7c22996 in pluginHook (handle=<optimized out>, id=<optimized out>, hookData=0x7f1ec6cbab20, 
    error=<optimized out>)
    at /usr/src/debug/subscription-manager-1.23.8-33.el8.x86_64/src/dnf-plugins/product-id/product-id.c:409
        repos = <optimized out>
        oldProductDb = 0x7f1eb8352d70
        err = 0x0
        dnfContext = 0x55cab5bd2130
        ret_val = <optimized out>
        enabledRepos = 0x7f1ed8001e40
        activeRepoAndProductIds = <optimized out>
        enabledRepoAndProductIds = <optimized out>
        disabledRepos = 0x55cab5d224a0
        productDb = 0x7f1eb8348e10
#5  0x00007f1ed7383a03 in libdnf::Plugins::hook (this=<optimized out>, 
    id=id@entry=PLUGIN_HOOK_ID_CONTEXT_TRANSACTION, hookData=hookData@entry=0x7f1ec6cbab20, error=error@entry=0x0)
    at /usr/include/c++/8/bits/unique_ptr.h:342
        pluginWithHandle = @0x55cab5b48bb0: {plugin = std::unique_ptr<libdnf::Plugin> = {get() = 0x55cab5bd0f70}, 

          handle = 0x55cab5b48bd0}
        __for_range = <optimized out>
        __for_begin = <optimized out>
        __for_end = <optimized out>
#6  0x00007f1ed72c6cd8 in dnf_context_plugin_hook (context=<optimized out>, 
    id=id@entry=PLUGIN_HOOK_ID_CONTEXT_TRANSACTION, hookData=hookData@entry=0x7f1ec6cbab20, error=error@entry=0x0)
    at /usr/src/debug/libdnf-0.22.5-4.el8.x86_64/libdnf/dnf-context.cpp:2371
        priv = <optimized out>
#7  0x00007f1ed72dc4dc in dnf_transaction_commit (transaction=0x55cab5b24360, goal=<optimized out>, 
    state=state@entry=0x55cab5bd3d50, error=error@entry=0x7f1ec6cbacd0)
    at /usr/src/debug/libdnf-0.22.5-4.el8.x86_64/libdnf/dnf-transaction.cpp:1468
        filename = <optimized out>
        tmp = <optimized out>
        allow_untrusted = <optimized out>
        is_update = <optimized out>
        ret = 1
        rc = <optimized out>
        verbosity = <optimized out>
        vs_flags = <optimized out>
        i = <optimized out>
        j = <optimized out>
        state_local = <optimized out>
        all_obsoleted = <optimized out>
        pkglist = <optimized out>
        pkg = <optimized out>
        pkg_tmp = <optimized out>
        problems_filter = <optimized out>
        rpmts_flags = 0
        priv = 0x55cab5b242d0
        swdb = 0x7f1ed000a000
        data = {<libdnf::PluginHookData> = {hookId = PLUGIN_HOOK_ID_CONTEXT_TRANSACTION}, 
          transaction = 0x55cab5b24360, goal = 0x7f1eb80e8370, state = 0x55cab5bd3d50}
        sack = 0x55cab5c66340
        rpmdb_version_sack = <optimized out>
        rpmdb_begin = "909:5c9924719dbb3505b12cdf933f0d32cf359b9160"
        rpmdb_end = "909:2915e42275a1ea65502bb0fb612c4beec24f1f63"
#8  0x00007f1edc2fed9c in pk_backend_transaction_download_commit (error=0x7f1ec6cbacd0, state=0x55cab5bd3d50, 
    job=0x55cab5e8e520) at pk-backend-dnf.c:2385
        ret = 1
        state_local = <optimized out>
        job_data = 0x55cab5d5b980
        ret = <optimized out>
        state_local = <optimized out>
        job_data = <optimized out>
#9  pk_backend_transaction_run (job=0x55cab5e8e520, state=0x7f1eb8001c20, error=0x7f1ec6cbacd0)
    at pk-backend-dnf.c:2560
        state_local = 0x55cab5bd3d50
        job_data = 0x55cab5d5b980
        ret = <optimized out>
        flags = <optimized out>
#10 0x00007f1edc300d68 in pk_backend_update_packages_thread (job=0x55cab5e8e520, params=<optimized out>, 
    user_data=<optimized out>) at pk-backend-dnf.c:3349
        state_local = <optimized out>
        pkg = <optimized out>
        job_data = 0x55cab5d5b980
        filters = 8
        ret = <optimized out>
        i = <optimized out>
        package_ids = 0x7f1eb80a9f80
        sack = 0x55cab5c66340
        error = 0x0
        hash = 0x7f1ed8003e40
        __func__ = "pk_backend_update_packages_thread"
#11 0x000055cab3fa1abe in pk_backend_job_thread_setup (thread_data=0x55cab5cdcab0) at pk-backend-job.c:726
        helper = 0x55cab5cdcab0
#12 0x00007f1eee301f9a in g_thread_proxy (data=0x55cab5c248f0) at gthread.c:784
        thread = 0x55cab5c248f0
        __func__ = "g_thread_proxy"
#13 0x00007f1eedbb92de in start_thread (arg=<optimized out>) at pthread_create.c:486
        ret = <optimized out>
        pd = <optimized out>
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139770160985856, 4596211037371805245, 140732518597726, 
                140732518597727, 140732518597856, 139770160983552, -4470798990421086659, -4470703471724810691}, 
              mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, 
              canceltype = 0}}}
        not_first_call = <optimized out>
#14 0x00007f1eed8e9a63 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.

Comment 1 Matej Marušák 2019-03-04 08:40:50 UTC
Created attachment 1540549 [details]
backtrace

Comment 2 Martin Pitt 2019-03-04 08:46:40 UTC
This is a very recent regression (within the last week), but almost surely not triggered by PackageKit or dnf directly, as the same version is on our previous image (where it doesn't crash).

pluginHook → getActive sounds like dnf is now checking subscriptions or similar, which may have been turned on recently?

Comment 3 Martin Pitt 2019-03-04 08:49:13 UTC
Reassigning to subscription-manager, as this is clearly a bug in src/dnf-plugins/product-id/product-id.c. It calls g_hash_table_contains() with a NULL key.

Comment 4 Matej Marušák 2019-03-04 09:01:10 UTC
Works with subscription-manager-1.23.8-29.el8.x86_64 breaks with subscription-manager-1.23.8-33.el8.x86_64

Comment 5 Martin Pitt 2019-03-04 09:21:26 UTC
This should be blocker+. Ironically, one of these two broke it:

* Fri Feb 22 2019 Christopher Snyder <csnyder@redhat.com> 1.23.8-30
- 1673934, 1673931: Increase stability of libdnf product-id plugin (jhnidek@redhat.com)

Comment 10 Martin Pitt 2019-03-05 08:13:41 UTC
Judging from the stack trace, this was introduced in https://github.com/candlepin/subscription-manager/commit/f494d0ff25e10 here:

            gchar *repo_name = dnf_package_get_origin(instPkg);
            if (g_hash_table_contains(activeRepos, repo_name) == FALSE) {

Obviously repo_name is NULL, i. e. this is for a package that doesn't have an origin.  This condition needs to be checked. It makes sense to simply skip the package, as it can't contribute to the rep search. I. e. a simple

            if (!repo_name)
                continue;

should do the trick.

This explains why it's not reproducible with just using standard RHEL packages. In our test suite we use a locally generated repo and rpm, i. e. something like a "third party RPM".

Comment 11 Martin Pitt 2019-03-05 09:15:16 UTC
Created attachment 1540872 [details]
reproducer script

I found a standalone reproducer. It's a bit more tricky than just "install one third-party RPM", but this reproduces the crash reliably for me on a current nightly RHEL 8.0 VM:

   curl -O https://piware.de/tmp/cockpit-ws-188.x-1.wip.el8.x86_64.rpm
   rpm -U --verbose cockpit-ws-188.x-1.wip.el8.x86_64.rpm
   python3 pkcrash.py

This is more or less a very simplified workflow of what happens in Cockpit's tests. We build rpms from master and update the VM's distro packages with these.

Comment 14 John Sefler 2019-03-08 17:27:07 UTC
Here are my reproducer steps on beaker system provisioned with DISTRO=RHEL-8.0.0-20190228.1 RC1 compose using the attachment provided in comment 11....

[root@kvm-01-guest14 ~]# dnf module enable python36 --quiet
Is this ok [y/N]: y
[root@kvm-01-guest14 ~]# dnf install python3 cockpit-ws rpm-build createrepo_c PackageKit --quiet
Is this ok [y/N]: y
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# rpm -q PackageKit subscription-manager cockpit-ws
PackageKit-1.1.12-2.el8.x86_64
subscription-manager-1.23.8-33.el8.x86_64
cockpit-ws-185-2.el8.x86_64
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# mkdir /tmp/beaker-repos
[root@kvm-01-guest14 ~]# cp /etc/yum.repos.d/beaker-* /tmp/beaker-repos
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# curl --stderr /dev/null -O https://piware.de/tmp/cockpit-ws-188.x-1.wip.el8.x86_64.rpm
[root@kvm-01-guest14 ~]# ls cockpit-ws-188.x-1.wip.el8.x86_64.rpm
cockpit-ws-188.x-1.wip.el8.x86_64.rpm
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# rpm -U --verbose cockpit-ws-188.x-1.wip.el8.x86_64.rpm
Verifying packages...
Preparing packages...
cockpit-ws-188.x-1.wip.el8.x86_64
cockpit-ws-185-2.el8.x86_64
[/usr/lib/tmpfiles.d/subscription-manager.conf:1] Line references path below legacy directory /var/run/, updating /var/run/rhsm → /run/rhsm; please update the tmpfiles.d/ drop-in file accordingly.
[root@kvm-01-guest14 ~]# rpm -q cockpit-ws
cockpit-ws-188.x-1.wip.el8.x86_64
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# curl --stderr /dev/null -G https://bugzilla.redhat.com/attachment.cgi?id=1540872 -o pkcrash.py
[root@kvm-01-guest14 ~]# ls pkcrash.py
pkcrash.py
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# python3 pkcrash.py
inactive
/sbin/ldconfig: Warning: ignoring configuration file that cannot be opened: /etc/ld.so.conf: No such file or directory
/sbin/ldconfig: Warning: ignoring configuration file that cannot be opened: /etc/ld.so.conf: No such file or directory
Directory walk started
Directory walk done - 2 packages
Temporary output repo path: /var/tmp/repo/.repodata/
Preparing sqlite DBs
Pool started (with 5 workers)
Pool finished
Updating Subscription Management repositories.
Unable to read consumer identity
This system is not registered to Red Hat Subscription Management. You can use subscription-manager to register.
0 files removed
Refreshing cache              [=========================]         
Starting                      [=========================]         
Finished                      [=========================]         
Getting updates               [=========================]         
Finished                      [=========================]         
Updating packages             [=========================]         
Loading cache                 [=========================]         
Finished                      [=========================]         
Updating packages             [=========================]         
Cleaning up packages          [                         ] (0%)  The daemon crashed mid-transaction!
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# journalctl --no-pager --since "1 minutes ago"
-- Logs begin at Fri 2019-03-08 11:05:13 EST, end at Fri 2019-03-08 16:05:24 EST. --
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com dbus-daemon[756]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.55' (uid=0 pid=19063 comm="pkcon refresh force " label="unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023")
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: Starting PackageKit Daemon...
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: daemon start
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com dbus-daemon[756]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: Started PackageKit Daemon.
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Registered Authentication Agent for unix-process:19063:420077 (system bus name :1.57 [/usr/bin/pkttyagent --notify-fd 10 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: uid 0 is trying to obtain org.freedesktop.packagekit.system-sources-refresh auth (only_trusted:0)
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: uid 0 obtained auth for org.freedesktop.packagekit.system-sources-refresh
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com dbus-daemon[756]: [system] Activating service name='com.redhat.SubscriptionManager' requested by ':1.58' (uid=0 pid=19078 comm="/usr/libexec/platform-python /usr/sbin/subscriptio" label="system_u:system_r:rpm_t:s0") (using servicehelper)
Mar 08 12:15:13 kvm-01-guest14.lab.eng.rdu2.redhat.com dbus-daemon[756]: [system] Successfully activated service 'com.redhat.SubscriptionManager'
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: refresh-cache transaction /1_baacbcbc from uid 0 finished with success after 769ms
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Unregistered Authentication Agent for unix-process:19063:420077 (system bus name :1.57, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Registered Authentication Agent for unix-process:19083:420166 (system bus name :1.62 [/usr/bin/pkttyagent --notify-fd 10 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: get-updates transaction /2_aacbbbab from uid 0 finished with success after 343ms
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: uid 0 is trying to obtain org.freedesktop.packagekit.system-update auth (only_trusted:1)
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: new update-packages transaction /3_ecaadccd scheduled from uid 0
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: uid 0 obtained auth for org.freedesktop.packagekit.system-update
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: update-packages transaction /3_ecaadccd from uid 0 finished with need-untrusted after 6ms
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: uid 0 is trying to obtain org.freedesktop.packagekit.package-install-untrusted auth (only_trusted:0)
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: new update-packages transaction /4_aabbacec scheduled from uid 0
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[19068]: uid 0 obtained auth for org.freedesktop.packagekit.package-install-untrusted
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com kernel: PK-Backend[19094]: segfault at 0 ip 00007f9068e159f4 sp 00007f9052542928 error 4 in libglib-2.0.so.0.5600.4[7f9068dda000+115000]
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com kernel: Code: 84 00 00 00 00 00 f3 0f 1e fa 48 83 ec 08 e8 23 f0 fd ff 85 c0 0f 94 c0 48 83 c4 08 0f b6 c0 c3 66 0f 1f 44 00 00 f3 0f 1e fa <0f> be 17 b8 05 15 00 00 84 d2 74 18 89 c1 48 83 c7 01 c1 e1 05 01
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: Created slice system-systemd\x2dcoredump.slice.
Mar 08 12:15:14 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: Started Process Core Dump (PID 19095/UID 0).
Mar 08 12:15:15 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: packagekit.service: Main process exited, code=killed, status=11/SEGV
Mar 08 12:15:15 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: packagekit.service: Failed with result 'signal'.
Mar 08 12:15:15 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Unregistered Authentication Agent for unix-process:19083:420166 (system bus name :1.62, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Mar 08 12:15:15 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd-coredump[19096]: Process 19068 (packagekitd) of user 0 dumped core.
                                                                                
                                                                                Stack trace of thread 19094:
                                                                                #0  0x00007f9068e159f4 g_str_hash (libglib-2.0.so.0)
                                                                                #1  0x00007f9068e151f8 g_hash_table_contains (libglib-2.0.so.0)
                                                                                #2  0x00007f90534a9c7e getActive (product-id.so)
                                                                                #3  0x00007f90534aa996 pluginHook (product-id.so)
                                                                                #4  0x00007f905eb7ea03 _ZN6libdnf7Plugins4hookE12PluginHookIdPNS_14PluginHookDataEPNS_11PluginErrorE (libdnf.so.2)
                                                                                #5  0x00007f905ead74dc dnf_transaction_commit (libdnf.so.2)
                                                                                #6  0x00007f9064382d9c pk_backend_transaction_run (libpk_backend_dnf.so)
                                                                                #7  0x00007f9064384d68 pk_backend_update_packages_thread (libpk_backend_dnf.so)
                                                                                #8  0x00005650f49e3abe pk_backend_job_thread_setup (packagekitd)
                                                                                #9  0x00007f9068e4ef9a g_thread_proxy (libglib-2.0.so.0)
                                                                                #10 0x00007f90687062de start_thread (libpthread.so.0)
                                                                                #11 0x00007f9068436a63 __clone (libc.so.6)
                                                                                
                                                                                Stack trace of thread 19068:
                                                                                #0  0x00007f906842b7e1 __poll (libc.so.6)
                                                                                #1  0x00007f9068e26bd6 g_main_context_iterate.isra.21 (libglib-2.0.so.0)
                                                                                #2  0x00007f9068e26f92 g_main_loop_run (libglib-2.0.so.0)
                                                                                #3  0x00005650f49ce629 main (packagekitd)
                                                                                #4  0x00007f906835d813 __libc_start_main (libc.so.6)
                                                                                #5  0x00005650f49ce8de _start (packagekitd)
                                                                                
                                                                                Stack trace of thread 19069:
                                                                                #0  0x00007f906842b7e1 __poll (libc.so.6)
                                                                                #1  0x00007f9068e26bd6 g_main_context_iterate.isra.21 (libglib-2.0.so.0)
                                                                                #2  0x00007f9068e26d00 g_main_context_iteration (libglib-2.0.so.0)
                                                                                #3  0x00007f9068e26d51 glib_worker_main (libglib-2.0.so.0)
                                                                                #4  0x00007f9068e4ef9a g_thread_proxy (libglib-2.0.so.0)
                                                                                #5  0x00007f90687062de start_thread (libpthread.so.0)
                                                                                #6  0x00007f9068436a63 __clone (libc.so.6)
                                                                                
                                                                                Stack trace of thread 19070:
                                                                                #0  0x00007f906842b7e1 __poll (libc.so.6)
                                                                                #1  0x00007f9068e26bd6 g_main_context_iterate.isra.21 (libglib-2.0.so.0)
                                                                                #2  0x00007f9068e26f92 g_main_loop_run (libglib-2.0.so.0)
                                                                                #3  0x00007f90694178aa gdbus_shared_thread_func (libgio-2.0.so.0)
                                                                                #4  0x00007f9068e4ef9a g_thread_proxy (libglib-2.0.so.0)
                                                                                #5  0x00007f90687062de start_thread (libpthread.so.0)
                                                                                #6  0x00007f9068436a63 __clone (libc.so.6)
                                                                                
                                                                                Stack trace of thread 19071:
                                                                                #0  0x00007f90684312bd syscall (libc.so.6)
                                                                                #1  0x00007f9068e6dcfe g_cond_wait_until (libglib-2.0.so.0)
                                                                                #2  0x00007f9068df90f1 g_async_queue_pop_intern_unlocked (libglib-2.0.so.0)
                                                                                #3  0x00007f9068e4fae2 g_thread_pool_thread_proxy (libglib-2.0.so.0)
                                                                                #4  0x00007f9068e4ef9a g_thread_proxy (libglib-2.0.so.0)
                                                                                #5  0x00007f90687062de start_thread (libpthread.so.0)
                                                                                #6  0x00007f9068436a63 __clone (libc.so.6)
Mar 08 12:15:29 kvm-01-guest14.lab.eng.rdu2.redhat.com restraintd[4544]: *** Current Time: Fri Mar 08 12:15:29 2019 Localwatchdog at:  * Disabled! *
[root@kvm-01-guest14 ~]# 

BANG! Notice "The daemon crashed mid-transaction!" and the systemd-coredump in journalctl.

Thank you Martin for the reproducer.

Comment 15 John Sefler 2019-03-08 19:14:56 UTC
Verification on the same system after updating subscription-manager (update details not shown)...

[root@kvm-01-guest14 ~]# yum update *subscription-manager* --quiet
Is this ok [y/N]: y
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# rpm -q PackageKit cockpit-ws dnf-plugin-subscription-manager
PackageKit-1.1.12-2.el8.x86_64
cockpit-ws-188.x-1.wip.el8.x86_64
dnf-plugin-subscription-manager-1.23.8-35.el8.x86_64
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# rpm -q dnf-plugin-subscription-manager  --changelog | grep 1685037
- 1685037: Ignore null repos when running using packagekit (csnyder@redhat.com)
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# python3 pkcrash.py
failed
/sbin/ldconfig: Warning: ignoring configuration file that cannot be opened: /etc/ld.so.conf: No such file or directory
/sbin/ldconfig: Warning: ignoring configuration file that cannot be opened: /etc/ld.so.conf: No such file or directory
Directory walk started
Directory walk done - 2 packages
Temporary output repo path: /var/tmp/repo/.repodata/
Preparing sqlite DBs
Pool started (with 5 workers)
Pool finished
Updating Subscription Management repositories.
Unable to read consumer identity
This system is not registered to Red Hat Subscription Management. You can use subscription-manager to register.
0 files removed
Refreshing cache              [=========================]         
Starting                      [=========================]         
Finished                      [=========================]         
Getting updates               [=========================]         
Finished                      [=========================]         
Updating packages             [=========================]         
Loading cache                 [=========================]         
Finished                      [=========================]         
Updating packages             [=========================]         
Cleaning up packages          [=========================]         
Finished                      [=========================]         
[root@kvm-01-guest14 ~]# 
[root@kvm-01-guest14 ~]# journalctl --no-pager --since "1 minutes ago"
-- Logs begin at Fri 2019-03-08 11:05:13 EST, end at Fri 2019-03-08 16:05:24 EST. --
Mar 08 14:09:29 kvm-01-guest14.lab.eng.rdu2.redhat.com restraintd[4544]: *** Current Time: Fri Mar 08 14:09:29 2019 Localwatchdog at:  * Disabled! *
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com dbus-daemon[756]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.87' (uid=0 pid=22962 comm="pkcon refresh force " label="unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023")
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: Starting PackageKit Daemon...
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: daemon start
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com dbus-daemon[756]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com systemd[1]: Started PackageKit Daemon.
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Registered Authentication Agent for unix-process:22962:1106842 (system bus name :1.89 [/usr/bin/pkttyagent --notify-fd 10 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: uid 0 is trying to obtain org.freedesktop.packagekit.system-sources-refresh auth (only_trusted:0)
Mar 08 14:09:40 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: uid 0 obtained auth for org.freedesktop.packagekit.system-sources-refresh
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: refresh-cache transaction /9_beccadbc from uid 0 finished with success after 502ms
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Unregistered Authentication Agent for unix-process:22962:1106842 (system bus name :1.89, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Registered Authentication Agent for unix-process:22981:1106908 (system bus name :1.92 [/usr/bin/pkttyagent --notify-fd 10 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: get-updates transaction /10_bddbcdea from uid 0 finished with success after 379ms
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: uid 0 is trying to obtain org.freedesktop.packagekit.system-update auth (only_trusted:1)
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: new update-packages transaction /11_daaeadbd scheduled from uid 0
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: uid 0 obtained auth for org.freedesktop.packagekit.system-update
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: update-packages transaction /11_daaeadbd from uid 0 finished with need-untrusted after 6ms
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: uid 0 is trying to obtain org.freedesktop.packagekit.package-install-untrusted auth (only_trusted:0)
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: new update-packages transaction /12_dbdbcecb scheduled from uid 0
Mar 08 14:09:41 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: uid 0 obtained auth for org.freedesktop.packagekit.package-install-untrusted
Mar 08 14:09:42 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: in /12_dbdbcecb for update-packages package chocolate;2.0-2;noarch;updates was updating for uid 0
Mar 08 14:09:42 kvm-01-guest14.lab.eng.rdu2.redhat.com PackageKit[22967]: update-packages transaction /12_dbdbcecb from uid 0 finished with success after 331ms
Mar 08 14:09:42 kvm-01-guest14.lab.eng.rdu2.redhat.com polkitd[741]: Unregistered Authentication Agent for unix-process:22981:1106908 (system bus name :1.92, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
[root@kvm-01-guest14 ~]# 

VERIFIED: packagekitd does not crash

Comment 16 Martin Pitt 2019-03-11 08:05:12 UTC
I also confirm that with the latest sub-man this PK crash is gone. Thanks!


Note You need to log in before you can comment on or make changes to this bug.