dunstify with --action won't print action chosen

Created on 11 Dec 2018 · 18Comments · Source: dunst-project/dunst

Dunstify indefinitely hangs, even after killing dunst.

Running dbus-monitor path=/org/freedesktop/Notifications | ts "[%T]", then calling dunstify --action=test,test test, choosing the option, dismissing the notification, then bringing up the notification again from history and choosing the option again.

[14:15:59] signal time=1544559359.727653 sender=org.freedesktop.DBus -> destination=:1.43134 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired
[14:15:59]    string ":1.43134"
[14:15:59] signal time=1544559359.727728 sender=org.freedesktop.DBus -> destination=:1.43134 serial=4 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost
[14:15:59]    string ":1.43134"
[14:16:09] method call time=1544559369.651003 sender=:1.43136 -> destination=:1.43135 serial=6 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=GetServerInformation
[14:16:09] method call time=1544559369.651931 sender=:1.43136 -> destination=:1.43135 serial=7 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=Notify
[14:16:09]    string "dunstify"
[14:16:09]    uint32 0
[14:16:09]    string ""
[14:16:09]    string "test"
[14:16:09]    string ""
[14:16:09]    array [
[14:16:09]       string "test"
[14:16:09]       string "test"
[14:16:09]    ]
[14:16:09]    array [
[14:16:09]       dict entry(
[14:16:09]          string "urgency"
[14:16:09]          variant             byte 1
[14:16:09]       )
[14:16:09]    ]
[14:16:09]    int32 -1
[14:16:12] signal time=1544559372.431432 sender=:1.43135 -> destination=:1.43136 serial=5 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=ActionInvoked
[14:16:12]    uint32 2
[14:16:12]    string "test"
[14:16:14] signal time=1544559374.392853 sender=:1.43135 -> destination=:1.43136 serial=6 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=NotificationClosed
[14:16:14]    uint32 2
[14:16:14]    uint32 2
[14:16:19] signal time=1544559379.879578 sender=:1.43135 -> destination=:1.43136 serial=7 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=ActionInvoked
[14:16:19]    uint32 2
[14:16:19]    string "test"

Installation info

Version: Dunst - A customizable and lightweight notification-daemon 1.3.2 (2018-05-06)
Install type: package
Distro and version: Manjaro (Rolling)

Oddly, this is currently working on my Arch install, but only intermittently.

external unconfirmed

Source

xPMo

All 18 comments

I'm not sure I understand how to reproduce this. Once I close the notification either by dismissing it or by selecting an action dunstify exits as intended.

dismissing the notification, then bringing up the notification again from history and choosing the option again.

This is not possible on master by the way, once a notification is closed it's assumed that the client has stopped listening (which most do) so we don't allow to re-send them.

tsipinakis on 12 Dec 2018

I cloned, make, make dunstify and ran master, but dunstify still hangs after I dismiss it.

I make debugd, and ran the same thing I did before (launch action notification, activated it, dismissed it, brought it up and activated it again). It seems as if it does assume the client has stopped listening, like you said (and like I've observed in the past).
Here is ./dunst -verbosity debug, timestamped:

[05:57:28] DEBUG: RUN
[05:57:28] DEBUG: XEvent: Ignoring '65'
[05:57:30] DEBUG: XEvent: Checking for active screen changes
[05:57:30] DEBUG: XEvent: Checking for active screen changes
[05:57:30] DEBUG: XEvent: Checking for active screen changes
[05:57:31] DEBUG: RUN
[05:57:31] DEBUG: XEvent: Ignoring '22'
[05:57:31] DEBUG: XEvent: Ignoring '22'
[05:57:31] DEBUG: XEvent: Ignoring '22'
[05:57:31] DEBUG: XEvent: Ignoring '22'
[05:57:31] DEBUG: XEvent: Ignoring '65'
[05:57:31] DEBUG: XEvent: Ignoring '22'
[05:57:31] DEBUG: XEvent: Ignoring '22'
[05:57:31] DEBUG: XEvent: Ignoring '19'
[05:57:31] DEBUG: XEvent: Ignoring '19'
[05:57:31] DEBUG: XEvent: Ignoring '15'
[05:57:31] DEBUG: XEvent: processing 'Expose'
[05:57:31] DEBUG: XEvent: Ignoring '65'
[05:57:32] DEBUG: XEvent: Checking for active screen changes
[05:57:32] DEBUG: XEvent: processing 'KeyPress'
[05:57:32] DEBUG: RUN
[05:57:32] DEBUG: posix_spawn avoided (automatic reaping requested) (fd close requested) 
[05:57:32] DEBUG: XEvent: Ignoring '65'
[05:57:32] DEBUG: XEvent: processing 'CreateNotify'
[05:57:32] DEBUG: XEvent: Ignoring '22'
[05:57:32] DEBUG: XEvent: Ignoring '22'
[05:57:32] DEBUG: XEvent: Ignoring '22'
[05:57:32] DEBUG: XEvent: Ignoring '19'
[05:57:32] DEBUG: XEvent: Ignoring '3'
[05:57:32] DEBUG: XEvent: Checking for active screen changes
[05:57:32] DEBUG: XEvent: Checking for active screen changes
[05:57:33] DEBUG: XEvent: Checking for active screen changes
[05:57:33] DEBUG: XEvent: Ignoring '18'
[05:57:33] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Checking for active screen changes
[05:57:35] DEBUG: XEvent: processing 'KeyPress'
[05:57:35] DEBUG: RUN
[05:57:35] DEBUG: XEvent: Ignoring '65'
[05:57:35] DEBUG: XEvent: Ignoring '3'
[05:57:35] DEBUG: XEvent: Checking for active screen changes
[05:57:35] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Ignoring '17'
[05:57:35] DEBUG: XEvent: Checking for active screen changes
[05:57:35] DEBUG: XEvent: processing 'KeyPress'
[05:57:35] DEBUG: RUN
[05:57:35] DEBUG: XEvent: Ignoring '18'
[05:57:35] DEBUG: XEvent: Ignoring '18'
[05:57:35] DEBUG: XEvent: Ignoring '3'
[05:57:35] DEBUG: XEvent: Checking for active screen changes
[05:57:36] DEBUG: XEvent: Checking for active screen changes
[05:57:36] DEBUG: XEvent: processing 'KeyPress'
[05:57:36] DEBUG: RUN
[05:57:36] DEBUG: XEvent: Ignoring '65'
[05:57:36] DEBUG: XEvent: Ignoring '19'
[05:57:36] DEBUG: XEvent: Ignoring '19'
[05:57:36] DEBUG: XEvent: Ignoring '15'
[05:57:36] DEBUG: XEvent: processing 'Expose'
[05:57:36] DEBUG: XEvent: Ignoring '65'
[05:57:36] DEBUG: XEvent: Ignoring '3'
[05:57:36] DEBUG: XEvent: Checking for active screen changes
[05:57:36] DEBUG: XEvent: Checking for active screen changes
[05:57:36] DEBUG: XEvent: processing 'KeyPress'
[05:57:36] DEBUG: RUN
[05:57:36] DEBUG: posix_spawn avoided (automatic reaping requested) (fd close requested) 
[05:57:36] DEBUG: XEvent: Ignoring '65'
[05:57:36] DEBUG: XEvent: processing 'CreateNotify'
[05:57:36] DEBUG: XEvent: Ignoring '22'
[05:57:36] DEBUG: XEvent: Ignoring '22'
[05:57:36] DEBUG: XEvent: Ignoring '3'
[05:57:36] DEBUG: XEvent: Ignoring '3'
[05:57:36] DEBUG: XEvent: Checking for active screen changes
[05:57:36] DEBUG: XEvent: Ignoring '22'
[05:57:36] DEBUG: XEvent: Ignoring '19'
[05:57:36] DEBUG: XEvent: Checking for active screen changes
[05:57:37] WARNING: Invoking action 'test' not supported. Notification already closed.
[05:57:37] DEBUG: XEvent: Checking for active screen changes
[05:57:37] DEBUG: XEvent: Ignoring '18'
[05:57:37] DEBUG: XEvent: Ignoring '17'
[05:57:38] DEBUG: XEvent: Checking for active screen changes
[05:57:38] DEBUG: XEvent: processing 'KeyPress'
[05:57:38] DEBUG: RUN
[05:57:38] DEBUG: XEvent: Ignoring '18'
[05:57:38] DEBUG: XEvent: Ignoring '18'
[05:57:39] DEBUG: XEvent: Ignoring '3'
[05:57:39] DEBUG: XEvent: Checking for active screen changes
[05:57:40] DEBUG: XEvent: Checking for active screen changes
[05:57:40] DEBUG: XEvent: Checking for active screen changes
[05:57:40] DEBUG: XEvent: Checking for active screen changes

Any other debugging steps you want me to take?

xPMo on 12 Dec 2018

Okay, I rebooted and the issue went away. In case this does crop up again for me, any suggestions?

xPMo on 12 Dec 2018

[05:57:36] DEBUG: posix_spawn avoided (automatic reaping requested) (fd close requested)

Do you have your dmenu command setup properly?

bebehei on 12 Dec 2018

I had the problem both for stock dmenu (default dunstrc), and for my preferred dmenu = /usr/bin/rofi -dmenu -p Action:

Either way, dmenu and rofi would run with the given actions as normal.

xPMo on 12 Dec 2018

From the dbus-monitor log, I don't see any issues with the dunst daemon. The daemon did everything right.

I'd suggest closing this issue. It may have been a weird issue with some libraries occuring during an update. Depending on your host's uptime and pacman upgrades, this might be reasonable.

I cannot reproduce it either. But if it happens to you ever again, reopen this bug. And if possible, bring a reproducer along. It'll help dramatically.

bebehei on 12 Dec 2018

👍1

Reopening. I use KDEConnect, and was trying to get my battery to show up as a notification with actions to do things with my device. But it always hung as above.

It turns out that if I ask KDE for a property relating to another device, and if, and only if it is currently connected, it will cause this.

$ qdbus org.kde.kdeconnect "/modules/kdeconnect/devices/$devid" org.kde.kdeconnect.device.isReachable
false
$ dunstify --action=a,a test
a
# opens phone so device reconnects
$ qdbus org.kde.kdeconnect "/modules/kdeconnect/devices/$devid" org.kde.kdeconnect.device.isReachable
true
$ dunstify --action=a,a test
# hangs, as will all further '--action'-enabled notifications

As before, exiting the session and re-logging-in will solve this. (I believe this resets dbus?)

xPMo on 27 Jan 2019

😕1

Ok, I used now 1.3.2 as dunst's main driver. But i still can't reproduce it. I only stumble upon old (and already fixed) bugs. [0]

Please send the logs of

killall dunst; dunst -print | ts "[%T] (please use your distro version and not master).
dbus-monitor path=/org/freedesktop/Notifications | ts "[%T]
Your complete dunstrc

And send your reproducing instructions.

[0] @tsipinakis We definitely have to do a release. There is so much currently fixed but unreleased OMG.

bebehei on 30 Jan 2019

@xPMo Do you have some additional info?

bebehei on 25 Feb 2019

Sorry, blame life for the delay.

Reproducing:

i3 4.16
kdeconnect 1.3.3
have a device connected
don't launch kdeconnect-indicator on startup while device is connected (it causes dunstify to break immediately)
script to log and reproduce:

#!/usr/bin/env bash
killall dunst
killall dbus-monitor
dunst -print | ts '[%T]' > /tmp/dunst.log &
dbus-monitor path=/org/freedesktop/Notifications | ts '[%T]' > /tmp/dbus.log &

dunstify --action=foo,bar summary body
dev="$(qdbus org.kde.kdeconnect /modules/kdeconnect org.kde.kdeconnect.daemon.devices | tail -n1)"
dunstify --action=foo,bar summary body
qdbus org.kde.kdeconnect "/modules/kdeconnect/devices/$dev" org.kde.kdeconnect.device.isReachable    # this prints true
dunstify --action=foo,bar summary body

Output:

foo
true

Choosing an action does not dismiss the notification or cause dunstify to return. Dismissing the notification does not cause dunstify to return.

xPMo on 26 Feb 2019

👍1

Well, I can't reproduce anything. Except for lines 85 and 114, the dbus.log file is clean.

Reproduce it with something other than kdeconnect and we can provide help. I don't have the kdeconnect configuration (and I don't want to have it).

I can't provide you with further help. Let's hope it got already fixed on current master.

bebehei on 26 Feb 2019

KDEConnect is obviously doing something to the bus.

I have 2 more ideas before I give up here as well:

Can you reproduce it again but run dbus-monitor without any parameters. This will show all the messages in the bus.
Run dunstify with gdb -ex run --args dunstify --action=...
Reproduce as usual until it hangs, hit ctrl+c in gdb and run 'backtrace' and post the entire output.

Now if this also reveals nothing, I'm out of clues as well.

tsipinakis on 26 Feb 2019

👍1

Plasma 5.16

method call time=1561419290.360445 sender=:1.292 -> destination=:1.285 serial=7 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=Notify
   string "dunstify"
   uint32 0
   string ""
   string "fgsdfg"
   string ""
   array [
      string "Y"
      string "Update now"
      string "N"
      string "Later"
   ]
   array [
      dict entry(
         string "urgency"
         variant             byte 1
      )
   ]
   int32 -1
method return time=1561419290.360613 sender=:1.28 -> destination=:1.292 serial=1970 reply_serial=7
   uint32 34
method return time=1561419290.388023 sender=:1.285 -> destination=:1.292 serial=558 reply_serial=7
   uint32 7
signal time=1561419290.482630 sender=org.freedesktop.DBus -> destination=:1.272 serial=6 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost
   string ":1.272"
signal time=1561419290.482649 sender=org.freedesktop.DBus -> destination=(null destination) serial=103 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged
   string ":1.272"
   string ":1.272"
   string ""
signal time=1561419292.526949 sender=:1.285 -> destination=(null destination) serial=559 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=ActionInvoked
   uint32 7
   string "Y"
signal time=1561419292.527152 sender=:1.285 -> destination=(null destination) serial=560 path=/org/freedesktop/Notifications; interface=org.freedesktop.Notifications; member=NotificationClosed
   uint32 7
   uint32 2

So it seems the destination dies before receiving the response.

gdb for dunstify

#0  0x00007ffff7b93667 in poll () at /usr/lib/libc.so.6
#1  0x00007ffff7cd27c0 in  () at /usr/lib/libglib-2.0.so.0
#2  0x00007ffff7cd37f2 in g_main_loop_run () at /usr/lib/libglib-2.0.so.0
#3  0x000055555555627b in main (argc=<optimized out>, argv=<optimized out>) at dunstify.c:355
        n = 0x555555567aa0
        err = 0x0
        l = <optimized out>

parkerlreed on 25 Jun 2019

Indeed, but there's something more weirder with the sender/destinations here.
From the first message we have sender=:1.292 -> destination=:1.285 so 1.292 is dunstify and 1.285 is the notification daemon.

But right after that there's

method return time=1561419290.360613 sender=:1.28 -> destination=:1.292 serial=1970 reply_serial=7
   uint32 34
method return time=1561419290.388023 sender=:1.285 -> destination=:1.292 serial=558 reply_serial=7
   uint32 7

Looks like _two_ daemons replied separately with a notification id? I'm really not sure how that is possible since from my understanding the daemon that starts first has exclusive control of the notification address.

Weird, no wonder dunstify gets confused and hangs.

tsipinakis on 25 Jun 2019

~~Yeah that's odd. I'm using the Plasma notifications without using dunst. Is dunstify attempting to run dunst daemon also (the second daemon that shows up)?~~

~~Other than that I'm not sure what could be up.~~ (I'm in the boat that I just want action buttons on my notification and dunstify is the only thing that even comes close to working)

EDIT: I just tried on my home desktop (Same Arch/Plasma setup) and it worked fine O.o I'll have to investigate whats going on with the laptop setup.

https://amdpowered.com/simplescreenrecorder-2019-06-25_10.45.28.mp4

parkerlreed on 25 Jun 2019

I figured out the culprit on my end. KDE Connect registers as another notification listener/service. As noted above, it seems to send an extra response which throws off dunstify.

Disconnecting KDE Connect on the laptop allow dunstify with actions to work properly.

Not sure if OP might have been having the same issue.

parkerlreed on 25 Jun 2019

Glad you could solve it!
@xPMo Ping also, if you're still having this issue, this might be it.

I'd recommend reporting this to the KDE bug tracker to get an opinion from them and/or a proper fix. For dunstify we're using the standard libnotify library which means other programs can misbehave in similar ways with this issue.

tsipinakis on 27 Jun 2019

Alright, I went ahead and reported it to the bug tracker.

Perhaps there's no way to get notification sync without breaking the spec, since KDEConnect needs access to the notifications too.

xPMo on 24 Jul 2019

Was this page helpful?

0 / 5 - 0 ratings