Dunst doesnt show notifications

[jheidbrink]

Currently I don't see notifications. When sending something with notify-send, this times out. The dunst logs don't show anything when I execute notify-send. Because of #1512 I have a wrapper around dunst that restarts dunst when it exits, but this doesn't happen here, dunst is continuously running. My dunst logs look unsuspicious I think:

[...]
Okt 27 16:45:09 INFO: Idle status queried: 0
Okt 27 16:45:09 INFO: Wayland: Hiding window
Okt 27 16:45:10 DEBUG: [         wake_up:0102] Waking up
Okt 27 16:45:10 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 27 16:45:10 INFO: Idle status queried: 0
Okt 27 16:45:10 INFO: Wayland: Hiding window
Okt 27 16:45:10 DEBUG: [         wake_up:0102] Waking up
Okt 27 16:45:10 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 27 16:45:10 INFO: Idle status queried: 0
Okt 27 16:45:10 INFO: Wayland: Hiding window
Okt 27 16:46:45 DEBUG: [         wake_up:0102] Waking up
Okt 27 16:46:45 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 27 16:46:45 INFO: Idle status queried: 0
Okt 27 16:46:45 INFO: Wayland: Hiding window
Okt 27 16:47:45 DEBUG: [         wake_up:0102] Waking up
Okt 27 16:47:45 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 27 16:47:45 INFO: Idle status queried: 0
Okt 27 16:47:45 INFO: Wayland: Hiding window
Okt 27 16:49:14 DEBUG: [         wake_up:0102] Waking up
Okt 27 16:49:14 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 27 16:49:14 INFO: Idle status queried: 0
Okt 27 16:49:14 INFO: Wayland: Hiding window
[...]

Unfortunately I have no clue how to debug this, but if anyone has an idea I can check this if it happens again.

[jheidbrink]

I think the dunst process was still running for a terminated sway session, which of course cannot work and isn't dunst's fault

[jheidbrink]

dunst is not showing notifications again - this time I can confidently say it shouldn't have anything to do with a terminated sway session.

These are the last logs:

Okt 29 10:53:31 DEBUG: [calculate_dimensions:0346] Notification dimensions 300x289
Okt 29 10:53:31 DEBUG: [            draw:1028] Window dimensions 309x295
Okt 29 10:53:31 DEBUG: [wl_display_surface:0719] Buffer size (scaled) 618x590
Okt 29 10:53:31 DEBUG: [             run:0167] Sleeping for 9988 ms
Okt 29 10:53:41 DEBUG: [             run:0135] RUN, reason 0: DUNST_TIMER
Okt 29 10:53:41 INFO: Idle status queried: 0
Okt 29 10:53:41 DEBUG: [signal_notification_closed:1116] Queues: Closing notification for reason: time
Okt 29 10:53:41 INFO: Wayland: Hiding window
Okt 29 10:53:56 DEBUG: [         wake_up:0102] Waking up
Okt 29 10:53:56 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 29 10:53:56 INFO: Idle status queried: 0
Okt 29 10:53:56 INFO: Wayland: Hiding window
Okt 29 10:54:21 DEBUG: [         wake_up:0102] Waking up
Okt 29 10:54:21 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 29 10:54:21 INFO: Idle status queried: 0
WARNING: Unable to parse markup: Unknown tag 'https:' on line 2 char 26
Okt 29 10:54:21 DEBUG: [calculate_dimensions:0346] Notification dimensions 300x289
Okt 29 10:54:21 DEBUG: [            draw:1028] Window dimensions 309x295
Okt 29 10:54:21 DEBUG: [wl_display_surface:0719] Buffer size (scaled) 618x590
Okt 29 10:54:21 DEBUG: [             run:0167] Sleeping for 9995 ms
Okt 29 10:54:31 DEBUG: [             run:0135] RUN, reason 0: DUNST_TIMER
Okt 29 10:54:31 INFO: Idle status queried: 0
Okt 29 10:54:31 DEBUG: [signal_notification_closed:1116] Queues: Closing notification for reason: time
Okt 29 10:54:31 INFO: Wayland: Hiding window
Okt 29 11:23:00 DEBUG: [         wake_up:0102] Waking up
Okt 29 11:23:00 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 29 11:23:00 INFO: Idle status queried: 0
Okt 29 11:23:00 INFO: Wayland: Hiding window
Okt 29 11:23:01 DEBUG: [         wake_up:0102] Waking up
Okt 29 11:23:01 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 29 11:23:01 INFO: Idle status queried: 0
Okt 29 11:23:01 INFO: Wayland: Hiding window
Okt 29 11:23:01 DEBUG: [         wake_up:0102] Waking up
Okt 29 11:23:01 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 29 11:23:01 INFO: Idle status queried: 0
Okt 29 11:23:01 INFO: Wayland: Hiding window
Okt 29 11:23:01 DEBUG: [         wake_up:0102] Waking up
Okt 29 11:23:01 DEBUG: [             run:0135] RUN, reason 1: DUNST_WAKEUP
Okt 29 11:23:01 INFO: Idle status queried: 0
Okt 29 11:23:01 INFO: Wayland: Hiding window

There is a suspicious break between 10:54:31 and 11:23:00. The wakeup log entries appear when I switch my terminal emulator to fullscreen or back. Maybe interesting: I have two instances of sway running, each on their own tty. I regularly switch between them - but this doesn't usually break dunst.

[bynect]

Maybe it's related to the other problem?
There is still work to do on the wayland backend unfortunately.
Just in case have you tried in xwayland mode?

[tienbg-zigexn]

I can confirm this issues. I could not even kill the dunst process to run it in debug mode:

systemctl --user stop dunst
killall dunst

[fedang]

maybe using something like this: https://github.com/wmww/wayland-debug
would help in debugging the problem?

[tienbg-zigexn]

I've noticed the conditions

1. Use second monitor (turn off the builtin one)
2. Go get lunch (let the screen lock and sleep)
3. Get back. Now dunst is failing

[fedang]

I've noticed the conditions

1. Use second monitor (turn off the builtin one)

2. Go get lunch (let the screen lock and sleep)

3. Get back. **Now dunst is failing**

this is the same problem of #1512. sleep/suspend is causing some problem

[fedang]

@jheidbrink it would be super helpful if you could use the wayland debugger to trace events. my guess is that there is a protocol error that is being silently ignored and further messages are ignored by the compositor

[tienbg-zigexn]

@fedang
I found my problem. The builtin monitor get enabled after I wake my machine up, so the notifications go there, not the second monitor. And since I closed the laptop, I didn't know that.

So the problem is not from dunst, but myself. Sorry for wasting your time.

[fedang]

Thanks for the classification 👍

[SOwOphie]

I also get dunst unable to open notification windows semi-regularly, on Niri. Dunst debug output also looks mundane to me. But I managed to capture the issue with wayland_debug. Here is the "bad" output for showing a number of notifications:

-3827.6672 G: → wl_buffer@21r.destroy()
-3827.6670 G: → wl_shm@6a.create_pool(id=new wl_shm_pool@20s, fd=fd 10, size=1000000)
-3827.6664 G: → wl_shm_pool@20s.create_buffer(id=new wl_buffer@19x, offset=0, width=500, height=500, stride=2000, format=0:argb8888)
-3827.6663 G: → wl_shm_pool@20s.destroy()
-3827.6655 G: → wl_buffer@19x.destroy()
-3827.6654 G: → wl_shm@6a.create_pool(id=new wl_shm_pool@18x, fd=fd 11, size=60600)
-3827.6654 G: → wl_shm_pool@18x.create_buffer(id=new wl_buffer@22r, offset=0, width=303, height=50, stride=1212, format=0:argb8888)
-3827.6654 G: → wl_shm_pool@18x.destroy()
-3827.6653 G: → wl_display@1a.sync(callback=new wl_callback@17r)
-3827.6648 G: wl_display@1a.delete_id(id=21) -- wl_buffer@21r.destroyed after 23.6475s ↲
-3827.6648 G: wl_display@1a.delete_id(id=20) -- wl_shm_pool@20s.destroyed after 0.0022s ↲
-3827.6648 G: wl_display@1a.delete_id(id=19) -- wl_buffer@19x.destroyed after 0.0016s ↲
-3827.6648 G: wl_display@1a.delete_id(id=18) -- wl_shm_pool@18x.destroyed after 0.0006s ↲
-3827.6648 G: wl_display@1a.delete_id(id=17) -- wl_callback@17r.destroyed after 0.0005s ↲
-3827.6648 G: wl_callback@17r.done(callback_data=0) ↲
-3827.6552 G: → wl_buffer@22r.destroy()
-3827.6550 G: → wl_shm@6a.create_pool(id=new wl_shm_pool@17s, fd=fd 10, size=1000000)
-3827.6550 G: → wl_shm_pool@17s.create_buffer(id=new wl_buffer@18y, offset=0, width=500, height=500, stride=2000, format=0:argb8888)
-3827.6550 G: → wl_shm_pool@17s.destroy()
-3827.6532 G: → wl_buffer@18y.destroy()
-3827.6531 G: → wl_shm@6a.create_pool(id=new wl_shm_pool@19y, fd=fd 11, size=173316)
-3827.6531 G: → wl_shm_pool@19y.create_buffer(id=new wl_buffer@20t, offset=0, width=303, height=143, stride=1212, format=0:argb8888)
-3827.6531 G: → wl_shm_pool@19y.destroy()
-3827.6528 G: → wl_display@1a.sync(callback=new wl_callback@21s)
-3827.6524 G: wl_display@1a.delete_id(id=22) -- wl_buffer@22r.destroyed after 0.0129s ↲
-3827.6524 G: wl_display@1a.delete_id(id=17) -- wl_shm_pool@17s.destroyed after 0.0026s ↲
-3827.6524 G: wl_display@1a.delete_id(id=18) -- wl_buffer@18y.destroyed after 0.0026s ↲
-3827.6524 G: wl_display@1a.delete_id(id=19) -- wl_shm_pool@19y.destroyed after 0.0007s ↲
-3827.6524 G: wl_display@1a.delete_id(id=21) -- wl_callback@21s.destroyed after 0.0004s ↲
-3827.6524 G: wl_callback@21s.done(callback_data=0) ↲
-3827.6344 G: → wl_buffer@20t.destroy()
-3827.6342 G: → wl_shm@6a.create_pool(id=new wl_shm_pool@21t, fd=fd 10, size=1000000)
-3827.6342 G: → wl_shm_pool@21t.create_buffer(id=new wl_buffer@19z, offset=0, width=500, height=500, stride=2000, format=0:argb8888)
-3827.6342 G: → wl_shm_pool@21t.destroy()
-3827.6310 G: → wl_buffer@19z.destroy()
-3827.6308 G: → wl_shm@6a.create_pool(id=new wl_shm_pool@18z, fd=fd 11, size=263004)
-3827.6308 G: → wl_shm_pool@18z.create_buffer(id=new wl_buffer@17t, offset=0, width=303, height=217, stride=1212, format=0:argb8888)
-3827.6308 G: → wl_shm_pool@18z.destroy()
-3827.6303 G: → wl_display@1a.sync(callback=new wl_callback@22s)
-3827.6296 G: wl_display@1a.delete_id(id=20) -- wl_buffer@20t.destroyed after 0.0235s ↲
-3827.6296 G: wl_display@1a.delete_id(id=21) -- wl_shm_pool@21t.destroyed after 0.0047s ↲
-3827.6296 G: wl_display@1a.delete_id(id=19) -- wl_buffer@19z.destroyed after 0.0046s ↲
-3827.6296 G: wl_display@1a.delete_id(id=18) -- wl_shm_pool@18z.destroyed after 0.0013s ↲
-3827.6296 G: wl_display@1a.delete_id(id=22) -- wl_callback@22s.destroyed after 0.0008s ↲
-3827.6296 G: wl_callback@22s.done(callback_data=0) ↲

(Are those leading dashes supposed to be there, or did I mess up some copy-pasting?) After a dunst restart, it looks like this:

29.5801 A: → wl_buffer@20a.destroy()
29.5802 A: → wl_shm@6a.create_pool(id=new wl_shm_pool@21b, fd=fd 10, size=1000000)
29.5803 A: → wl_shm_pool@21b.create_buffer(id=new wl_buffer@22b, offset=0, width=500, height=500, stride=2000, format=0:argb8888)
29.5803 A: → wl_shm_pool@21b.destroy()
29.5809 A: → wl_buffer@22b.destroy()
29.5810 A: → wl_shm@6a.create_pool(id=new wl_shm_pool@19e, fd=fd 11, size=60600)
29.5810 A: → wl_shm_pool@19e.create_buffer(id=new wl_buffer@23d, offset=0, width=303, height=50, stride=1212, format=0:argb8888)
29.5810 A: → wl_shm_pool@19e.destroy()
29.5811 A: → wl_compositor@4a.create_surface(id=new wl_surface@18b)
29.5811 A: → zwlr_layer_shell_v1@5a.get_layer_surface(id=new zwlr_layer_surface_v1@17c, surface=wl_surface@18b, output=null wl_output, layer=3:overlay, namespace='notifications')
29.5811 A: → zwlr_layer_surface_v1@17c.set_size(width=303, height=50)
29.5811 A: → zwlr_layer_surface_v1@17c.set_anchor(anchor=8:right)
29.5811 A: → zwlr_layer_surface_v1@17c.set_margin(top=0, right=0, bottom=0, left=0)
29.5812 A: → wl_surface@18b.commit()
29.5812 A: → wl_display@1a.sync(callback=new wl_callback@24a)
29.5837 A: wl_display@1a.delete_id(id=20) -- wl_buffer@20a.destroyed after 12.1052s ↲
29.5837 A: wl_display@1a.delete_id(id=21) -- wl_shm_pool@21b.destroyed after 0.0035s ↲
29.5837 A: wl_display@1a.delete_id(id=22) -- wl_buffer@22b.destroyed after 0.0035s ↲
29.5837 A: wl_display@1a.delete_id(id=19) -- wl_shm_pool@19e.destroyed after 0.0028s ↲
29.5837 A: wl_display@1a.delete_id(id=24) -- wl_callback@24a.destroyed after 0.0026s ↲
29.5837 A: wl_surface@18b.enter(output=wl_output@11a) ↲
29.5837 A: zwlr_layer_surface_v1@17c.configure(serial=256125, width=303, height=50) ↲
29.5838 A: → zwlr_layer_surface_v1@17c.ack_configure(serial=256125)
29.5838 A: → wl_surface@18b.set_buffer_scale(scale=1)
29.5838 A: → wl_surface@18b.damage_buffer(x=0, y=0, width=2147483647, height=2147483647)
29.5838 A: → wl_surface@18b.attach(buffer=wl_buffer@23d, x=0, y=0)
29.5838 A: → wl_surface@18b.frame(callback=new wl_callback@19f)
29.5838 A: → wl_surface@18b.commit()
29.5838 A: wl_callback@24a.done(callback_data=0) ↲
29.5838 A: → wl_display@1a.sync(callback=new wl_callback@24b)
29.5916 A: wl_display@1a.delete_id(id=24) -- wl_callback@24b.destroyed after 0.0078s ↲
29.5916 A: wl_display@1a.delete_id(id=19) -- wl_callback@19f.destroyed after 0.0078s ↲
29.5916 A: wl_callback@24b.done(callback_data=0) ↲
29.5917 A: wl_callback@19f.done(callback_data=22050415) ↲
29.5966 A: → wl_shm@6a.create_pool(id=new wl_shm_pool@19g, fd=fd 10, size=1000000)
29.5972 A: → wl_shm_pool@19g.create_buffer(id=new wl_buffer@24c, offset=0, width=500, height=500, stride=2000, format=0:argb8888)
29.5972 A: → wl_shm_pool@19g.destroy()
29.6102 A: → wl_buffer@24c.destroy()
29.6104 A: → wl_shm@6a.create_pool(id=new wl_shm_pool@22c, fd=fd 11, size=150288)
29.6104 A: → wl_shm_pool@22c.create_buffer(id=new wl_buffer@21c, offset=0, width=303, height=124, stride=1212, format=0:argb8888)
29.6104 A: → wl_shm_pool@22c.destroy()
29.6107 A: → wl_surface@18b.frame(callback=new wl_callback@20b)
29.6107 A: → wl_surface@18b.commit()
29.6108 A: → wl_display@1a.sync(callback=new wl_callback@25a)
29.6123 A: wl_display@1a.delete_id(id=19) -- wl_shm_pool@19g.destroyed after 0.0157s ↲
29.6124 A: wl_display@1a.delete_id(id=24) -- wl_buffer@24c.destroyed after 0.0152s ↲
29.6124 A: wl_display@1a.delete_id(id=22) -- wl_shm_pool@22c.destroyed after 0.0020s ↲
29.6124 A: wl_display@1a.delete_id(id=25) -- wl_callback@25a.destroyed after 0.0017s ↲
29.6124 A: wl_display@1a.delete_id(id=20) -- wl_callback@20b.destroyed after 0.0018s ↲
29.6125 A: wl_callback@25a.done(callback_data=0) ↲
29.6125 A: wl_callback@20b.done(callback_data=22050436) ↲
29.6125 A: → zwlr_layer_surface_v1@17c.set_size(width=303, height=124)
29.6126 A: → zwlr_layer_surface_v1@17c.set_anchor(anchor=8:right)
29.6126 A: → zwlr_layer_surface_v1@17c.set_margin(top=0, right=0, bottom=0, left=0)
29.6126 A: → wl_surface@18b.commit()
29.6127 A: → wl_display@1a.sync(callback=new wl_callback@20c)
29.6131 A: wl_display@1a.delete_id(id=20) -- wl_callback@20c.destroyed after 0.0004s ↲
29.6131 A: zwlr_layer_surface_v1@17c.configure(serial=256126, width=303, height=124) ↲
29.6132 A: → zwlr_layer_surface_v1@17c.ack_configure(serial=256126)
29.6132 A: → wl_surface@18b.set_buffer_scale(scale=1)
29.6132 A: → wl_surface@18b.damage_buffer(x=0, y=0, width=2147483647, height=2147483647)
29.6132 A: → wl_surface@18b.attach(buffer=wl_buffer@21c, x=0, y=0)
29.6132 A: → wl_surface@18b.frame(callback=new wl_callback@25b)
29.6133 A: → wl_surface@18b.commit()
29.6133 A: wl_callback@20c.done(callback_data=0) ↲
29.6191 A: wl_buffer@23d.release() ↲
29.6235 A: wl_display@1a.delete_id(id=25) -- wl_callback@25b.destroyed after 0.0102s ↲
29.6235 A: wl_callback@25b.done(callback_data=22050447) ↲

I vaguely suspect that Gammastep adjustments might be involved. But I have not been able to consistently reproduce the issue.