anacron blocks resume from suspend

This failure seems to be easily reproducible for me with 2.6.31-10.32

Note I am running with ~ubuntu-boot PPA packages as well

I'm also just adding a note about bug 408860 which was an earlier suspend/resume bug Matt reported against the same hw reported here.

Further investigation shows this failure is not only unrelated to the warning in bug 429001, but also doesn't look like a kernel problem:

root 2024 0.0 0.3 6932 3732 ? S Sep14 0:14 /usr/lib/devicekit-power/devkit-power-daemon
root 17328 0.0 0.0 1848 556 ? S Sep15 0:00 \_ /bin/sh /usr/sbin/pm-suspend
root 17598 0.0 0.0 1848 496 ? S 09:42 0:00 \_ /bin/sh /usr/lib/pm-utils/sleep.d/95anacron resume
root 17599 0.0 0.0 2316 824 ? S 09:42 0:00 \_ start -q anacron

that's where the resume process is hung. I assume it's running the scripts in reverse order, and so as 95anacron never completes, it doesn't get to 55NetworkManager (which explains why networking is disabled).

ii upstart 0.6.3-2~boot8 event-based init daemon

Is anacron running?

On Wed, Sep 16, 2009 at 04:51:43PM -0000, Scott James Remnant wrote:
> Is anacron running?

atomicity:[~] ps aux |grep anacron
mdz 18485 0.0 0.0 2188 780 pts/5 S+ 10:17 0:00 grep anacron

--
 - mdz

On Wed, 2009-09-16 at 17:17 +0000, Matt Zimmerman wrote:

> On Wed, Sep 16, 2009 at 04:51:43PM -0000, Scott James Remnant wrote:
> > Is anacron running?
>
> atomicity:[~] ps aux |grep anacron
> mdz 18485 0.0 0.0 2188 780 pts/5 S+ 10:17 0:00 grep anacron
>
But the "start" command is still blocking?

Could you try "status anacron"

Scott
--
Scott James Remnant
<email address hidden>

On Wed, Sep 16, 2009 at 06:05:08PM -0000, Scott James Remnant wrote:
> On Wed, 2009-09-16 at 17:17 +0000, Matt Zimmerman wrote:
>
> > On Wed, Sep 16, 2009 at 04:51:43PM -0000, Scott James Remnant wrote:
> > > Is anacron running?
> >
> > atomicity:[~] ps aux |grep anacron
> > mdz 18485 0.0 0.0 2188 780 pts/5 S+ 10:17 0:00 grep anacron
> >
> But the "start" command is still blocking?
>
> Could you try "status anacron"

I upgraded to the latest Karmic, and something clobbered this state
(perhaps the anacron upgrade stopping and starting it?).

I haven't been able to reproduce the problem yet with the latest bits (now
running all Karmic, with the ubuntu-boot PPA packages superseded).

--
 - mdz

/var/log/pm-suspend.log attached

atomicity:[~] grep anacron /var/log/pm-suspend.log
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspend suspend: stop: Unknown instance:
/usr/lib/pm-utils/sleep.d/95anacron resume suspend: success.
/usr/lib/pm-utils/sleep.d/95anacron suspe...

On Wed, 2009-09-16 at 18:20 +0000, Matt Zimmerman wrote:

> I upgraded to the latest Karmic, and something clobbered this state
> (perhaps the anacron upgrade stopping and starting it?).
>
Could you have had packages from the ubuntu-boot PPA installed?

The anacron that was there certainly had this bug, and anacron was one
of the last things to get built in the archive.

Scott
--
Scott James Remnant
<email address hidden>

On Wed, Sep 16, 2009 at 08:14:17PM -0000, Scott James Remnant wrote:
> On Wed, 2009-09-16 at 18:20 +0000, Matt Zimmerman wrote:
>
> > I upgraded to the latest Karmic, and something clobbered this state
> > (perhaps the anacron upgrade stopping and starting it?).
> >
> Could you have had packages from the ubuntu-boot PPA installed?

I definitely did, yes (as noted in comment #3).

--
 - mdz

Great, this can be marked Fixed then

On Wed, Sep 16, 2009 at 08:14:17PM -0000, Scott James Remnant wrote:
> Could you have had packages from the ubuntu-boot PPA installed?
>
> The anacron that was there certainly had this bug, and anacron was one
> of the last things to get built in the archive.

I've just reproduced the bug again. I think it may only happen when the
system has been suspended for a period of time (in recent cases, overnight).

root 3858 0.0 0.0 1836 512 ? S 09:25 0:00 \_ /bin/sh /usr/lib/pm-utils/sleep.d/95anacron resume suspend
root 3859 0.0 0.0 2304 828 ? S 09:25 0:00 \_ start -q anacron
root 3861 0.0 0.0 1764 580 ? Ss 09:25 0:00 anacron -s

ii anacron 2.3-13.1ubuntu9 cron-like program that doesn't go by time

--
 - mdz

Here's where start(8) is blocked:

(gdb) bt full
#0 0x0065e422 in __kernel_vsyscall ()
No symbol table info available.
#1 0x00242b6b in poll () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.
#2 0x0016f10b in _dbus_poll (fds=0xbfa33734, n_fds=1, timeout_milliseconds=-1) at dbus-sysdeps-unix.c:1970
No locals.
#3 0x001670df in socket_do_iteration (transport=0x1438518, flags=6, timeout_milliseconds=-1) at dbus-transport-socket.c:1066
        poll_fd = {fd = 3, events = 1, revents = 0}
        poll_res = 6
        poll_timeout = -1
#4 0x001652fc in _dbus_transport_do_iteration (transport=0x1438518, flags=6, timeout_milliseconds=-1) at dbus-transport.c:956
No locals.
#5 0x0014fbf3 in _dbus_connection_do_iteration_unlocked (connection=0x1438928, flags=6, timeout_milliseconds=1) at dbus-connection.c:1163
No locals.
#6 0x00152344 in _dbus_connection_block_pending_call (pending=0x1438bd0) at dbus-connection.c:2423
        start_tv_sec = 21209452
        start_tv_usec = 8
        tv_sec = 1253204795
        tv_usec = 453647
        status = <value optimized out>
        connection = 0x1438928
        client_serial = 2
        timeout = 0x0
        timeout_milliseconds = -1
        elapsed_milliseconds = -1
#7 0x0015fa81 in dbus_pending_call_block (pending=0xfffffdfc) at dbus-pending-call.c:705
        __FUNCTION__ = "dbus_pending_call_block"
#8 0x00811ab2 in start_action (command=0x1438074, args=0x1438364) at initctl.c:406
        upstart = 0x1438b34
        upstart_job = 0x1438384 "anacron"
        upstart_instance = 0x0
        job_class_path = 0x143a12c "/com/ubuntu/Upstart/jobs/anacron"
        job_class = 0x143a16c
        job_path = 0x0
        job = 0x0
        pending_call = <value optimized out>
        ret = 1
        err = <value optimized out>
        __FUNCTION__ = "start_action"
#9 0x0082664e in nih_command_handle (parent=<value optimized out>, argc=<value optimized out>, argv=0xbfa33ab4, options=0x8350f8, commands=0x1438074, command=0x1438074) at command.c:344
        cmd_opts = <value optimized out>
        opts = 0x14381c4
        ret = -1
        __FUNCTION__ = "nih_command_handle"
#10 0x008267a5 in nih_command_parser (parent=0x0, argc=3, argv=0xbfa33ab4, options=0x8350f8, commands=0x83514c) at command.c:135
        cmds = 0x1438074
        cmd = 0x1438074
        footer = 0x0
        stem = 0x0
        args = 0x0
        arg = <value optimized out>
        ret = <value optimized out>
        __FUNCTION__ = "nih_command_parser"
#11 0x008100aa in main (argc=3, argv=0xbfa33ab4) at initctl.c:1372
        ret = <value optimized out>
#12 0x0019ab56 in __libc_start_main () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.
#13 0x0080ff51 in _start () at ../sysdeps/i386/elf/start.S:106
No locals.

On Thu, 2009-09-17 at 16:34 +0000, Matt Zimmerman wrote:

> Here's where start(8) is blocked:
>
> (gdb) bt full
>
This is not interesting ;) But if you could provide the "ps" and
"status" output as before ... ?

Scott
--
Scott James Remnant
<email address hidden>

On Thu, 2009-09-17 at 16:29 +0000, Matt Zimmerman wrote:

> On Wed, Sep 16, 2009 at 08:14:17PM -0000, Scott James Remnant wrote:
> > Could you have had packages from the ubuntu-boot PPA installed?
> >
> > The anacron that was there certainly had this bug, and anacron was one
> > of the last things to get built in the archive.
>
> I've just reproduced the bug again. I think it may only happen when the
> system has been suspended for a period of time (in recent cases, overnight).
>
> root 3858 0.0 0.0 1836 512 ? S 09:25 0:00 \_ /bin/sh /usr/lib/pm-utils/sleep.d/95anacron resume suspend
> root 3859 0.0 0.0 2304 828 ? S 09:25 0:00 \_ start -q anacron
> root 3861 0.0 0.0 1764 580 ? Ss 09:25 0:00 anacron -s
>
> ii anacron 2.3-13.1ubuntu9
> cron-like program that doesn't go by time
>
Oh, you did. LP just delivered them out of order.

It's not actually failing - it's just running your cron scripts and
waiting for them. Probably shouldn't be waiting <g>

There's two possible fixes for this:

 1) remove "task" from /etc/init/anacron.conf

 2) add "-n" to that start invocation

I suspect that the "task" is the right one.

Scott
--
Scott James Remnant
<email address hidden>

This bug was fixed in the package anacron - 2.3-13.1ubuntu10

---------------
anacron (2.3-13.1ubuntu10) karmic; urgency=low

  * debian/upstart: anacron should not be a task, otherwise
    "start anacron" (as used in many scripts) will block. It's just a
    short-lived service. LP: #429009.

 -- Scott James Remnant <email address hidden> Thu, 17 Sep 2009 20:28:52 +0100