dbus problem: "notifications-notify :on-action" stops working

dbus problem: "notifications-notify :on-action" stops working

[Peter Münster]

Hi,

Sometimes, the call-back function specified in ":on-action" of the
`notifications-notify' function is no more called and I have to restart
emacs to make it work again.

I was able (but not always) to reproduce this problem with this simple
test file:

--8<---------------cut here---------------start------------->8---
(require 'notifications)

(defun my-test-action (id ignore)
  (message "Success (id = %d)" id))

(defun my-test ()
  (interactive)
  (message "Begin test (id = %d)"
           (notifications-notify
            :title     "title"
            :timeout   30000
            :actions   '("key" "click here")
            :on-action 'my-test-action)))

(global-set-key [?\C-a] 'my-test)
(switch-to-buffer "*Messages*")
--8<---------------cut here---------------end--------------->8---

I save it in /tmp/init.el and start "emacs -Q -l /tmp/init.el". Then I
press about a dozen times "C-a" followed by a click on "click here".
Then I wait about 2-3 minutes and try it again: no more "Success".

Can others reproduce this behaviour?

Where could be the problem, and how could I debug it?

TIA for any help!
-- 
           Peter

Re: dbus problem: "notifications-notify :on-action" stops working

[Michael Albinus]

Peter Münster <pmlists@free.fr> writes:

> Hi,

Hi,

> Can others reproduce this behaviour?

Which Emacs version are you using?

> Where could be the problem, and how could I debug it?

Setting `dbus-debug' to t is a starting point. If the resulting messages
are confusing you, you might run instead "dbus-monitor --session" in a
shell outside Emacs

> TIA for any help!

Best regards, Michael.

Re: dbus problem: "notifications-notify :on-action" stops working

[Peter Münster]

On Mon, Feb 27 2012, Michael Albinus wrote:

> Which Emacs version are you using?

GNU Emacs 24.0.93.1 (x86_64-suse-linux-gnu, GTK+ Version 2.22.1) of 2012-02-24


> Setting `dbus-debug' to t is a starting point. If the resulting messages
> are confusing you, you might run instead "dbus-monitor --session" in a
> shell outside Emacs

Of course! I had forgotten dbus-debug...

Now I have 2 emacs sessions: one, where it's working as expected, and
another with the problem:

Here the output, where it's working:

--8<---------------cut here---------------start------------->8---
xd_retrieve_arg: u 2
xd_retrieve_arg: s key
xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 20 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications ActionInvoked (2 key)
xd_read_message_1: Event stored: (:session 4 20 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications ActionInvoked notifications-on-action-signal 2 key)
xd_retrieve_arg: u 2 [2 times]
xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 21 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications NotificationClosed (2 2)
xd_read_message_1: Event stored: (:session 4 21 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications NotificationClosed notifications-on-closed-signal 2 2)
--8<---------------cut here---------------end--------------->8---

Here the output with the problem:

--8<---------------cut here---------------start------------->8---
xd_retrieve_arg: u 4
xd_retrieve_arg: s hour
xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 38 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications ActionInvoked (4 hour)
xd_retrieve_arg: u 4
xd_retrieve_arg: u 2
xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 39 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications NotificationClosed (4 2)
--8<---------------cut here---------------end--------------->8---


When I call

--8<---------------cut here---------------start------------->8---
  (dbus-register-signal
   :session
   notifications-service
   notifications-path
   notifications-interface
   notifications-action-signal
   'notifications-on-action-signal)
--8<---------------cut here---------------end--------------->8---

in the second emacs session, the problem disappears for a while and then
comes back after a few minutes.

-- 
           Peter

Re: dbus problem: "notifications-notify :on-action" stops working

[Michael Albinus]

Peter Münster <pmlists@free.fr> writes:

Hi,

I've played a while with the recipe you gave the other mail. No problem.

Note, that I'm running Ubuntu 11.10.

> Now I have 2 emacs sessions: one, where it's working as expected, and
> another with the problem:
>
> Here the output, where it's working:
>
> xd_retrieve_arg: u 2
> xd_retrieve_arg: s key
> xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 20 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications ActionInvoked (2 key)
> xd_read_message_1: Event stored: (:session 4 20 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications ActionInvoked notifications-on-action-signal 2 key)
> xd_retrieve_arg: u 2 [2 times]
> xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 21 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications NotificationClosed (2 2)
> xd_read_message_1: Event stored: (:session 4 21 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications NotificationClosed notifications-on-closed-signal 2 2)
>
> Here the output with the problem:
>
> xd_retrieve_arg: u 4
> xd_retrieve_arg: s hour
> xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 38 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications ActionInvoked (4 hour)
> xd_retrieve_arg: u 4
> xd_retrieve_arg: u 2
> xd_read_message_1: Event received: DBUS_MESSAGE_TYPE_SIGNAL 39 :1.278 /org/freedesktop/Notifications org.freedesktop.Notifications NotificationClosed (4 2)

The difference is, that in the second case there is no "Event stored"
trace. That means, that the Emacs session does not feel responsible for
the incoming D-Bus event. No idea, why.

I've played also with two Emacs sessions in parallel, and there was no
problem. When I have typed C-a in both Emacs session, and I have pressed
the notification window, the "Success" message was visible in the Emacs
buffer where I have pressed the last C-a. That's acceptable.

Maybe you could replay your scenario, and let dbus-monitor run in
parallel. Please comment exactly what you have done (starting Emacs,
every keystroke), and mark the corresponding traces from
dbus-monitor. By this, we might be able to understand what happens.

Best regards, Michael.

Re: dbus problem: "notifications-notify :on-action" stops working

[Peter Münster]

On Mon, Feb 27 2012, Michael Albinus wrote:

> Maybe you could replay your scenario, and let dbus-monitor run in
> parallel. Please comment exactly what you have done (starting Emacs,
> every keystroke), and mark the corresponding traces from
> dbus-monitor. By this, we might be able to understand what happens.

Hi Michael,

Yesterday evening, after a reboot of the system, I've started my normal
emacs session and "dbus-monitor --session" and "dbus-monitor --profile".
"--profile", because there are timestamps.

Sometimes, I've started another "emacs -Q -l /tmp/init.el" just to see,
if it works or not. Now, the problem appears again, at timestamp
"1330414472". Here the "*Messages*":

--8<---------------cut here---------------start------------->8---
Begin test (id = 23)
Success (id = 23)
Begin test (id = 24)
Success (id = 24)
Begin test (id = 25)
Success (id = 25)
Begin test (id = 26)
Success (id = 26)
Begin test (id = 27)
Success (id = 27)
Begin test (id = 28)
Success (id = 28)
Begin test (id = 4)
Begin test (id = 5)
--8<---------------cut here---------------end--------------->8---

The output of dbus-monitor is perhaps too big for usenet, so you can
find it here: http://pmrb.free.fr/tmp/dbus/



Another test:
I've restarted the 2 dbus-monitors, and also "emacs -Q -l /tmp/init.el".

I've added this to my init.el:

--8<---------------cut here---------------start------------->8---
(defun my-register-again ()
  (interactive)
  (dbus-register-signal
   :session
   notifications-service
   notifications-path
   notifications-interface
   notifications-action-signal
   'notifications-on-action-signal))

(global-set-key [?\C-b] 'my-register-again)
--8<---------------cut here---------------end--------------->8---


The results:

--8<---------------cut here---------------start------------->8---
Begin test (id = 11)
Success (id = 11)
Begin test (id = 12)
Success (id = 12)
Begin test (id = 13)
Success (id = 13)
Begin test (id = 14)
Success (id = 14)
Begin test (id = 15)
Success (id = 15)
##################### Here I've waited for some minutes.
Begin test (id = 3)
Begin test (id = 4)
Begin test (id = 5)
##################### Here I've pressed "C-b" !
Begin test (id = 6)
Success (id = 6)
Begin test (id = 7)
Success (id = 7)
Begin test (id = 8)
Success (id = 8)
Begin test (id = 9)
Success (id = 9)
##################### Here I've waited for some minutes.
Begin test (id = 1)
Begin test (id = 2)
Begin test (id = 3)
--8<---------------cut here---------------end--------------->8---

And here the dbus-output: http://pmrb.free.fr/tmp/dbus2/

I hope, that you have some time to look at this and can find what's
going on.

Thanks for your efforts,
-- 
           Peter

Re: dbus problem: "notifications-notify :on-action" stops working

[Michael Albinus]

Peter Münster <pmlists@free.fr> writes:

> Hi Michael,

Hi Peter,

sorry for the delay, it took some hours to walk through the dbus-monitor
traces.

> Sometimes, I've started another "emacs -Q -l /tmp/init.el" just to see,
> if it works or not. Now, the problem appears again, at timestamp
> "1330414472". Here the "*Messages*":

According to the traces, you have two Emacs sessions running, sending
notifications to the notification service. It looks, like a notification
daemon wants to be unique for a given client, sending the
notifications. As long as you send notifications from the same client
(aka Emacs session), the daemon stays alive, and does the work.

If another client sends a notification message, the running daemon is
disabled in the D-Bus name owner queue, and a new notification daemon is
started for that client. The point is, that this new daemon is still
reachable via the known name "org.freedesktop.Notifications", but is has
another unique D-Bus name (like ":1.5" or so).

notifications.el registers for signals from the D-Bus service
"org.freedesktop.Notifications". But during registration, this service
name is translated into the D-Bus unique name of the daemon, running at
*this* time. When another daemon takes over the service name
"org.freedesktop.Notifications", it has another D-Bus unique name, for
which notifications.el has not registered. That's why you don't see the
signals anymore.

I have prepared a patch, which shall handle this situation. Could you,
please, check?

--8<---------------cut here---------------start------------->8---
*** /home/albinus/src/emacs/lisp/notifications.el.~107473~	2012-03-01 15:08:08.000000000 +0100
--- /home/albinus/src/emacs/lisp/notifications.el	2012-03-01 15:08:09.000000000 +0100
***************
*** 91,107 ****
  (defvar notifications-on-close-map nil
    "Mapping between notification and close callback functions.")

  (defun notifications-on-action-signal (id action)
    "Dispatch signals to callback functions from `notifications-on-action-map'."
    (let ((entry (assoc id notifications-on-action-map)))
!     (when entry
        (funcall (cadr entry) id action)
        (remove entry 'notifications-on-action-map))))

  (when (fboundp 'dbus-register-signal)
    (dbus-register-signal
     :session
!    notifications-service
     notifications-path
     notifications-interface
     notifications-action-signal
--- 91,114 ----
  (defvar notifications-on-close-map nil
    "Mapping between notification and close callback functions.")

+ (defvar notifications-service-name ""
+   "Unique service name of notification daemon.
+ This must be kept, because the notification daemon could be
+ restarted, and the registered signals cannot be identified anymore.")
+
  (defun notifications-on-action-signal (id action)
    "Dispatch signals to callback functions from `notifications-on-action-map'."
    (let ((entry (assoc id notifications-on-action-map)))
!     (when (and entry
! 	       (string-equal notifications-service-name
! 			     (dbus-event-service-name last-input-event)))
        (funcall (cadr entry) id action)
        (remove entry 'notifications-on-action-map))))

  (when (fboundp 'dbus-register-signal)
    (dbus-register-signal
     :session
!    nil
     notifications-path
     notifications-interface
     notifications-action-signal
***************
*** 113,119 ****
    ;; make it optional, and assume `undefined' as default.
    (let ((entry (assoc id notifications-on-close-map))
  	(reason (or reason 4)))
!     (when entry
        (funcall (cadr entry)
  	       id (cadr (assoc reason notifications-closed-reason)))
        (remove entry 'notifications-on-close-map))))
--- 120,128 ----
    ;; make it optional, and assume `undefined' as default.
    (let ((entry (assoc id notifications-on-close-map))
  	(reason (or reason 4)))
!     (when (and entry
! 	       (string-equal notifications-service-name
! 			     (dbus-event-service-name last-input-event)))
        (funcall (cadr entry)
  	       id (cadr (assoc reason notifications-closed-reason)))
        (remove entry 'notifications-on-close-map))))
***************
*** 121,127 ****
  (when (fboundp 'dbus-register-signal)
    (dbus-register-signal
     :session
!    notifications-service
     notifications-path
     notifications-interface
     notifications-closed-signal
--- 130,136 ----
  (when (fboundp 'dbus-register-signal)
    (dbus-register-signal
     :session
!    nil
     notifications-path
     notifications-interface
     notifications-closed-signal
***************
*** 277,282 ****
--- 286,295 ----
                              (or hints '(:array :signature "{sv}"))
                              :int32 (or timeout -1)))

+     ;; Remember daemon unique service name.
+     (setq notifications-service-name
+ 	  (dbus-get-name-owner :session notifications-service))
+
      ;; Register close/action callback function
      (let ((on-action (plist-get params :on-action))
            (on-close (plist-get params :on-close)))
--8<---------------cut here---------------end--------------->8---

> Thanks for your efforts,

Best regards, Michael.

Re: dbus problem: "notifications-notify :on-action" stops working

[Peter Münster]

On Thu, Mar 01 2012, Michael Albinus wrote:

> I have prepared a patch, which shall handle this situation. Could you,
> please, check?

Thank you for the patch, no problem during the last 3 days!
So I think, that the patch is good.

-- 
           Peter

Re: dbus problem: "notifications-notify :on-action" stops working

[Michael Albinus]

Peter Münster <pmlists@free.fr> writes:

>> I have prepared a patch, which shall handle this situation. Could you,
>> please, check?
>
> Thank you for the patch, no problem during the last 3 days!
> So I think, that the patch is good.

I've committed a modified version of the patch to the trunk.

Best regards, Michael.