@xet7 Alright, here’s hoping those fixes hit the spot! Thanks a lot.

And now, suddenly, it just works again.

root@saegusa:~# snap install wekan
wekan 0.77-29-g9e62584 from 'xet7' installed

root@battra:~# snap install wekan
2018/03/02 16:39:13.986937 cmd.go:212: DEBUG: restarting into "/snap/core/current/usr/bin/snap"
wekan 0.77-29-g9e62584 from 'xet7' installed

Darn it, I was hoping to catch the exact cause. Unless you guys already found and fixed it?

What’s changed on my end since I posted the last comment a week ago is the core snap updating from 4017 to 4110.

@kubiko Output from snap changes and snap change below, syslog output (with snapd debugging enabled) attached here.

root@battra:~# snap changes
ID   Status  Spawn                 Ready                 Summary
30   Error   2018-02-22T09:55:45Z  2018-02-22T10:02:02Z  Install "wekan" snap from "edge" channel
31   Error   2018-02-22T10:27:51Z  2018-02-22T10:33:04Z  Install "wekan" snap from file "wekan_0.76-22-g31f25bc_amd64.snap"
32   Error   2018-02-22T12:05:21Z  2018-02-22T12:10:33Z  Install "wekan" snap from file "wekan_0.76-22-g31f25bc-dirty_amd64.snap"
33   Error   2018-02-22T12:12:20Z  2018-02-22T12:17:32Z  Install "wekan" snap from file "wekan_0.76-22-g31f25bc-dirty_amd64.snap"
34   Error   2018-02-22T12:25:15Z  2018-02-22T12:30:28Z  Install "wekan" snap from file "wekan_0.76-22-g31f25bc-dirty_amd64.snap"
35   Error   2018-02-22T15:28:37Z  2018-02-22T15:33:54Z  Install "wekan" snap
36   Error   2018-02-23T06:24:32Z  2018-02-23T06:31:05Z  Install "wekan" snap

root@battra:~# snap change 36
Status  Spawn                 Ready                 Summary
Done    2018-02-23T06:24:32Z  2018-02-23T06:31:05Z  Ensure prerequisites for "wekan" are available
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:05Z  Download snap "wekan" (128) from channel "stable"
Done    2018-02-23T06:24:32Z  2018-02-23T06:31:04Z  Fetch and check assertions for snap "wekan" (128)
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:04Z  Mount snap "wekan" (128)
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:03Z  Copy snap "wekan" data
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:03Z  Setup snap "wekan" (128) security profiles
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:02Z  Make snap "wekan" (128) available to the system
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:01Z  Set automatic aliases for snap "wekan"
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:01Z  Setup snap "wekan" aliases
Done    2018-02-23T06:24:32Z  2018-02-23T06:31:01Z  Run install hook of "wekan" snap if present
Undone  2018-02-23T06:24:32Z  2018-02-23T06:31:01Z  Start snap "wekan" (128) services
Error   2018-02-23T06:24:32Z  2018-02-23T06:31:00Z  Run configure hook of "wekan" snap if present

......................................................................
Run configure hook of "wekan" snap if present

2018-02-23T08:31:00+02:00 ERROR run hook "configure": <exceeded maximum runtime of 5m0s>

@kubiko Thanks for taking a look!

I have two systems affected by this, both running Ubuntu 16.04[.3] LTS desktop and both tracking the core snap, with the following specifics:

Server (though with Ubuntu desktop installed)

This system is running stock 16.04 (no -proposed or HW) and Apache doing proxying. I had previously installed the snap on this system, set my root-url and changed the port to 3333 (IIRC), and it was running fine when the issue occurred sometime around the January 15th refresh. I’ve since removed the snap along with the settings so the attempts on this system should in theory be clean installs.

17.33 jani@battra:~$ uname -a
Linux battra 4.4.0-112-generic #135-Ubuntu SMP Fri Jan 19 11:48:36 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
17.33 jani@battra:~$ snap version
snap    2.31
snapd   2.31
series  16
ubuntu  16.04
kernel  4.4.0-112-generic
17.33 jani@battra:~$ snap info core
name:      core
summary:   snapd runtime environment
publisher: canonical
contact:   snappy-canonical-storeaccount@canonical.com
license:   unknown
description: |
  The core runtime environment for snapd
type:        core
snap-id:     99T7MUlRhtI3U0QFgl5mXXESAiSwt776
tracking:    stable
installed:   16-2.31 (4017) 85MB core
refreshed:   2018-02-06 17:18:04 +0200 EET
channels:                                  
  stable:    16-2.31                (4017) 85MB -
  candidate: 16-2.31.1              (4110) 85MB -
  beta:      16-2.31.1              (4110) 85MB -
  edge:      16-2.31+git586.d89ba3c (4127) 85MB -
17.34 jani@battra:~$ snap list
Name  Version  Rev   Developer  Notes
core  16-2.31  4017  canonical  core

Main desktop

This system has the -proposed repository enabled and the HWE stack installed, no proxy. I’ve only ever attempted to install Wekan on this system after the issue occurred on the other system, and it has never succeeded (so in that sense it’s a clean install… attempt anyway).

17.08 jani@saegusa:~$ uname -a
Linux saegusa 4.13.0-36-generic #40~16.04.1-Ubuntu SMP Fri Feb 16 23:25:58 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
17.11 jani@saegusa:~$ snap version
snap    2.31.1
snapd   2.31.1
series  16
ubuntu  16.04
kernel  4.13.0-36-generic
17.11 jani@saegusa:~$ snap info core
name:      core
summary:   snapd runtime environment
publisher: canonical
contact:   snappy-canonical-storeaccount@canonical.com
license:   unknown
description: |
  The core runtime environment for snapd
type:        core
snap-id:     99T7MUlRhtI3U0QFgl5mXXESAiSwt776
tracking:    stable
installed:   16-2.31 (4017) 85MB core
refreshed:   2018-02-06 17:18:04 +0200 EET
channels:                                  
  stable:    16-2.31                (4017) 85MB -
  candidate: 16-2.31.1              (4110) 85MB -
  beta:      16-2.31.1              (4110) 85MB -
  edge:      16-2.31+git586.d89ba3c (4127) 85MB -
17.12 jani@saegusa:~$ snap list
Name  Version  Rev   Developer  Notes
core  16-2.31  4017  canonical  core

Since the issue with Wekan occurred, I’ve tried installing other snaps (on both systems) and they all work just fine.

If there’s anything else you need or something I missed, please let me know and I’ll be happy to provide.

I’m fairly sure it’s a matter of some configuration these two systems happen to have, and the Wekan snap issue is mainly just that of it not failing gracefully under the circumstances and leaving me in the dark about the exact cause.

Still no fix I’m afraid, but watching /var/snap/wekan/common/hook.log did provide a clue. The hook appears to get stuck at snapctl get caddy-enabled, after that there are no more entries.

I tried tweaking the hook by replacing value=$(snapctl get caddy-enabled) with value="", but installing the resulting snap then just gets stuck at the next snapctl call:

+ '[' '' = true ']'
+ snapctl stop --disable wekan.caddy

There’s also an ’error running snapctl: unknown service: ”caddy-service”’ line in syslog, but this seems to occur just alike on systems where the installation does not get stuck, so I’m not sure if it’s relevant.

Over at Launchpad, Jamie Strandboge had this to say:

”As for install/refresh getting stuck, it seems that the wekan hooks aren’t exiting so snapd has no choice but to wait a while then timeout.

At this point, this seems like the issues are in the wekan snap: it needs to plug hardware-observe and needs to handle error conditions better in the hooks so the exit.”

Just a minor ”no update” update: SRU 2.31 of snapd arrived via -proposed, but did not resolve this issue unfortunately.

I moved my Wekan installation to a VM until the installation issue gets resolved. In the meanwhile I can confirm that 1) the double slash issue is fixed now and 2) this edge-to-edge URL issue is still there.

I went ahead and reported this on Launchpad, we’ll see if anyone there has any ideas. A new SRU (2.30) of snapd also seems to be in the works, but no release as of yet.

(This came up for me in Wekan issue #1389)

When I try to install the snap (in Ubuntu 16.04), it gets stuck in Run configure hook of "wekan" snap if present. At this time Wekan service is already up and running, but snapd gives up on the configuration after a (built-in) 5 minute timeout and undoes the installation. (I initially thought the Node process was misbehaving, but I no longer think that’s the case here.)

Wekan snap issue #10 seems like the same problem. I enabled snap debugging as mentioned there, and will attach the result of grep snapd from during the installation attempt here.

While the service is up during the configuration phase, it produces journal log entries as usual and I’m attaching the relevant lines here.

I’ve tried purging and reinstalling snapd, disabling IPv6, turning off Apache and any other services that might be in the way (though none of them have caused issues previously), rebuilding the snap with my previous settings built in but none of it has made any difference.

In addition to my main server, I’ve since reproduced this on my desktop machine, and failed to reproduce it on another desktop and a VM with a fairly clean Ubuntu 16.04 install. The only difference between the reproducing and non-reproducing systems I’ve so far found is an Apparmor denial in /var/log/kern.log:

apparmor="DENIED" operation="open" profile="snap.wekan.mongodb" name="/sys/block/" pid=9478 comm="mongod" requested_mask="r" denied_mask="r" fsuid=0 ouid=0

The systems where Apparmor denies mongodb’s access to /sys/block get stuck at the configure hook, whereas systems that don’t report a denial finish the configuration (and installation) successfully.

I haven’t done any customization of Apparmor rules on any of these that I can remember; it’s pretty much dark arts to me which is why I’ve avoided touching it.