Re: F26 dnf makecache timer hanging

2017-07-18 Thread Chris Murphy
On Tue, Jul 18, 2017 at 10:10 AM, Alexander Ploumistos
 wrote:
> It's probably this bug:
> https://bugzilla.redhat.com/show_bug.cgi?id=1470352
>
> Daiki Ueno has sent a patch upstream.

Sounds like that's it.


-- 
Chris Murphy
___
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org


Re: F26 dnf makecache timer hanging

2017-07-18 Thread Alexander Ploumistos
It's probably this bug:
https://bugzilla.redhat.com/show_bug.cgi?id=1470352

Daiki Ueno has sent a patch upstream.
___
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org


Re: F26 dnf makecache timer hanging

2017-07-18 Thread Richard W.M. Jones
On Tue, Jul 18, 2017 at 07:54:06AM -0600, Chris Murphy wrote:
> [chris@f26s ~]$ sudo strace -p 3379
> strace: Process 3379 attached
> futex(0x55eabc09e110, FUTEX_WAIT_PRIVATE, 2, NULL
> 
> Anyway it seems like a bug but figured I'd ask and see if anyone else
> is experiencing this.

Could it be the infamous libdb bug ..

  https://bugzilla.redhat.com/show_bug.cgi?id=1394862 ?

I don't think anyone has seen that bug affecting ‘dnf’, but I suppose
it's possible it might happen if your RPM db is one of the old ones.

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
virt-top is 'top' for virtual machines.  Tiny program with many
powerful monitoring features, net stats, disk stats, logging, etc.
http://people.redhat.com/~rjones/virt-top
___
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org


Re: F26 dnf makecache timer hanging

2017-07-18 Thread Zbigniew Jędrzejewski-Szmek
On Tue, Jul 18, 2017 at 04:17:31PM +0200, Kamil Paral wrote:
> On Tue, Jul 18, 2017 at 3:54 PM, Chris Murphy 
> wrote:
> 
> > [chris@f26s ~]$ sudo dnf update
> > Waiting for process with pid 3379 to finish.
> > ^CKeyboardInterrupt: Terminated.
> >
> 
> I haven't seen this exact problem (timer blocking standard dnf command),
> but I started experience dnf hangs when downloading repo metadata or
> packages. Dnf simply hangs and no amount of waiting fixes it (I waited 10
> minutes, no message printed to terminal, no new message in dnf.librepo.log,
> still hanging). We tried to debug this today on #yum channel, but the logs
> look fine, cause is unknown.
> 
> Also, Ctrl+C doesn't work while in this state. I have to send SIGTERM to
> dnf to kill it. Once I run it again, everything works fine.
> 
> dnf-2.5.1-1.fc26.noarch

It's a long shot... but see also 
https://bugzilla.redhat.com/show_bug.cgi?id=1468896
(anaconda "hangs" at "Preparing transaction from installation source").
If dnf hung, that'd give the same effect.

Zbyszek
___
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org


Re: F26 dnf makecache timer hanging

2017-07-18 Thread Kamil Paral
On Tue, Jul 18, 2017 at 3:54 PM, Chris Murphy 
wrote:

> [chris@f26s ~]$ sudo dnf update
> Waiting for process with pid 3379 to finish.
> ^CKeyboardInterrupt: Terminated.
>

I haven't seen this exact problem (timer blocking standard dnf command),
but I started experience dnf hangs when downloading repo metadata or
packages. Dnf simply hangs and no amount of waiting fixes it (I waited 10
minutes, no message printed to terminal, no new message in dnf.librepo.log,
still hanging). We tried to debug this today on #yum channel, but the logs
look fine, cause is unknown.

Also, Ctrl+C doesn't work while in this state. I have to send SIGTERM to
dnf to kill it. Once I run it again, everything works fine.

dnf-2.5.1-1.fc26.noarch
___
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org


F26 dnf makecache timer hanging

2017-07-18 Thread Chris Murphy
I have a new problem I haven't seen until recently on Fedora 26 (I
don't recall running into this during development, so I'm guessing
it's only shown up in the last month). This is on Fedora 26 Server but
should apply equally to Workstation:

So what you'll see below is the timer triggers pretty much once an
hour, and I guess figures out whether it's stale or not and if it is
it downloads new metadata. But then at a certain point it just hangs
and stops updating for hours and hours, and then I can't run dnf
because it's already running.

Continues after the journal output...


[chris@f26s ~]$ sudo journalctl -b | grep dnf
[sudo] password for chris:
Jul 17 18:23:38 f26s.localdomain systemd[1]: Started dnf makecache timer.
Jul 17 18:33:20 f26s.localdomain systemd[1]: Starting dnf makecache...
Jul 17 18:33:29 f26s.localdomain dnf[1358]: Last metadata expiration
check: 0:41:45 ago on Mon 17 Jul 2017 05:51:42 PM MDT.
Jul 17 18:33:29 f26s.localdomain dnf[1358]: Metadata cache created.
Jul 17 18:33:29 f26s.localdomain systemd[1]: Started dnf makecache.
Jul 17 18:33:29 f26s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 18:33:29 f26s.localdomain audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 19:34:10 f26s.localdomain systemd[1]: Starting dnf makecache...
Jul 17 19:34:11 f26s.localdomain dnf[1750]: Metadata cache refreshed recently.
Jul 17 19:34:11 f26s.localdomain systemd[1]: Started dnf makecache.
Jul 17 19:34:11 f26s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 19:34:11 f26s.localdomain audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 20:34:20 f26s.localdomain systemd[1]: Starting dnf makecache...
Jul 17 20:34:21 f26s.localdomain dnf[2021]: Metadata cache refreshed recently.
Jul 17 20:34:21 f26s.localdomain systemd[1]: Started dnf makecache.
Jul 17 20:34:21 f26s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 20:34:21 f26s.localdomain audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 21:35:20 f26s.localdomain systemd[1]: Starting dnf makecache...
Jul 17 21:36:28 f26s.localdomain dnf[2337]: Last metadata expiration
check: 0:00:00 ago on Mon 17 Jul 2017 09:36:27 PM MDT.
Jul 17 21:36:31 f26s.localdomain dnf[2337]: Metadata cache created.
Jul 17 21:36:31 f26s.localdomain systemd[1]: Started dnf makecache.
Jul 17 21:36:31 f26s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 21:36:31 f26s.localdomain audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 22:37:10 f26s.localdomain systemd[1]: Starting dnf makecache...
Jul 17 22:37:11 f26s.localdomain dnf[2621]: Metadata cache refreshed recently.
Jul 17 22:37:11 f26s.localdomain systemd[1]: Started dnf makecache.
Jul 17 22:37:11 f26s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 22:37:11 f26s.localdomain audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 23:37:20 f26s.localdomain systemd[1]: Starting dnf makecache...
Jul 17 23:37:21 f26s.localdomain dnf[2894]: Metadata cache refreshed recently.
Jul 17 23:37:21 f26s.localdomain systemd[1]: Started dnf makecache.
Jul 17 23:37:21 f26s.localdomain audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Jul 17 23:37:21 f26s.localdomain audit[1]: S