snappy go does not always catch s-i dbus signal
| Affects | Status | Importance | Assigned to | Milestone | |
|---|---|---|---|---|---|
| Snappy |
Invalid
|
Undecided
|
Unassigned | ||
| go-dbus |
Fix Committed
|
Undecided
|
Unassigned | ||
Bug Description
Sometime running the go version will give:
Data with https:/
# ./snappy update
signal sender=
string ":1.8"
string ""
string ":1.8"
signal sender=
string ":1.9"
string ""
string ":1.9"
signal sender=
string "com.canonical.
string ""
string ":1.9"
signal sender=:1.0 -> dest=(null destination) serial=257 path=/org/
string "org.freedeskto
array [
dict entry(
string "MainPID"
variant uint32 0
)
dict entry(
string "ControlPID"
variant uint32 0
)
dict entry(
string "StatusText"
variant string ""
)
dict entry(
string "StatusErrno"
variant int32 0
)
dict entry(
string "Result"
variant string "success"
)
dict entry(
string "ExecMainStartT
variant uint64 0
)
dict entry(
string "ExecMainStartT
variant uint64 0
)
dict entry(
string "ExecMainExitTi
variant uint64 0
)
dict entry(
string "ExecMainExitTi
variant uint64 0
)
dict entry(
string "ExecMainPID"
variant uint32 0
)
dict entry(
string "ExecMainCode"
variant int32 0
)
dict entry(
string "ExecMainStatus"
variant int32 0
)
]
array [
string "ExecStartPre"
string "ExecStart"
string "ExecStartPost"
string "ExecReload"
string "ExecStop"
string "ExecStopPost"
]
signal sender=:1.0 -> dest=(null destination) serial=258 path=/org/
string "org.freedeskto
array [
dict entry(
string "ActiveState"
variant string "active"
)
dict entry(
string "SubState"
variant string "exited"
)
dict entry(
string "InactiveExitTi
variant uint64 1422957865219669
)
dict entry(
string "InactiveExitTi
variant uint64 7946903
)
dict entry(
string "ActiveEnterTim
variant uint64 1422957865290019
)
dict entry(
string "ActiveEnterTim
variant uint64 8017252
)
dict entry(
string "ActiveExitTime
variant uint64 0
)
dict entry(
string "ActiveExitTime
variant uint64 0
)
dict entry(
string "InactiveEnterT
variant uint64 0
)
dict entry(
string "InactiveEnterT
variant uint64 0
)
dict entry(
string "Job"
variant struct {
}
)
dict entry(
string "ConditionResult"
variant boolean true
)
dict entry(
string "AssertResult"
variant boolean true
)
dict entry(
string "ConditionTimes
variant uint64 1422957865210174
)
dict entry(
string "ConditionTimes
variant uint64 7937421
)
dict entry(
string "AssertTimestamp"
variant uint64 1422957865210189
)
dict entry(
string "AssertTimestam
variant uint64 7937422
)
]
array [
]
signal sender=:1.0 -> dest=(null destination) serial=1 path=/org/
string "/system.
signal sender=:1.9 -> dest=(null destination) serial=11 path=/Service; interface=
boolean false
boolean false
string ""
int32 0
string "2015-02-03 09:31:42"
string ""
ERROR: timed out after 30 seconds waiting for system image server to respond
signal sender=
string ":1.8"
string ":1.8"
string ""
Without the extra debug:
$ snappy update
ERROR: timed out after 30 seconds waiting for system image server to respond
Upon further investigation it turns out that the system-image server does indeed responds as shown by dbus-monitor --system:
"""
$ sudo ./snappy update
signal sender=
string ":1.15"
string ""
string ":1.15"
signal sender=
string ":1.16"
string ""
string ":1.16"
signal sender=
string "com.canonical.
string ""
string ":1.16"
signal sender=:1.16 -> dest=(null destination) serial=11 path=/Service; interface=
boolean true
boolean false
string "266"
int32 29293320
string "2015-02-03 07:42:10"
string ""
ERROR: timed out after 30 seconds waiting for system image server to respond
signal sender=
ubuntu@localhost:~$ string ":1.15"
string ":1.15"
string ""
"""
So it seems that our go-dbus code (or the underlying library) does not always pick up the signal
Related branches
- John Lenton: Approve
-
Diff: 60 lines (+6/-6)2 files modifiedsignal.go (+2/-2)
signal_test.go (+4/-4)
| description: | updated |
| Michael Vogt (mvo) wrote | #1 |
| Michael Vogt (mvo) wrote | #2 |
| Changed in snappy-ubuntu: | |
| status: | New → Invalid |
| Changed in go-dbus: | |
| status: | New → Fix Committed |
| affects: | snappy-ubuntu → snappy |
Here is a minimal test program. When I run it on my snappy box I get (with dbus-moitor running).
I can usually reproduce this when I kill the daemon and it gets dbus-activated. Subsequent runs work as expected. I wonder if it could be that the signal filter is created when there is no system-image on the dbus (yet).
The output of dbus-monitor:
# ./lala
signal sender=
string ":1.13"
string ""
string ":1.13"
signal sender=
string ":1.14"
string ""
string ":1.14"
signal sender=
string "com.canonical.
string ""
string ":1.14"
signal sender=:1.14 -> dest=(null destination) serial=10 path=/Service; interface=
boolean true
boolean false
string "266"
int32 29293320
string "2015-02-03 07:42:10"
string ""
panic: ERROR: timed out after 30 seconds waiting for system image server to respond