Bug 208774 - mail-notification chews CPU due to false 'folder-changed' notifications
Summary: mail-notification chews CPU due to false 'folder-changed' notifications
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: mail-notification
Version: 6
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Thorsten Leemhuis
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On: 223659
Blocks:
TreeView+ depends on / blocked
 
Reported: 2006-10-01 21:24 UTC by David Woodhouse
Modified: 2007-11-30 22:11 UTC (History)
2 users (show)

Fixed In Version: 4.0-1
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2007-02-15 16:36:33 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
Workaround (550 bytes, patch)
2006-10-04 15:56 UTC, David Woodhouse
no flags Details | Diff
potential fix (for 4.0-RC1) (17.18 KB, patch)
2006-12-01 06:07 UTC, Jean-Yves Lefort
no flags Details | Diff
new fix (16.23 KB, patch)
2006-12-04 10:21 UTC, Jean-Yves Lefort
no flags Details | Diff

Description David Woodhouse 2006-10-01 21:24:06 UTC
I've turned off 'Display seen mail', because I only want to be notified of
unread mail. My mailboxes have thousands of messages in, and it would be
cumbersome to have mail-notification dealing with that.

However, it seems to be using the (fairly pointless) IMAP definition of 'SEEN'
-- that is, the mail is 'seen' if any mail client has ever selected the folder
since the mail was delivered.

That's not wonderfully useful at the best of times -- but it's particularly
unhelpful in this case because even having a local Evolution running somewhere
with that folder open will mean that the mail is considered 'seen'. 

And since the whole point in using mail-notification was so that I'd be prompted
to go and _look_ at the running Evolution when it has new mail, that renders the
exercise mostly pointless. Evp will usually be sitting (at the back of my
desktop) with my INBOX open, and that means that mail-notification will never
tell me about new mail.

Instead of a 'Display seen mail' checkbox, we should probably have a 'Display
unread mail' checkbox, which will do what I _thought_ the 'Display seen mail'
checkbox was doing to do.

Comment 1 David Woodhouse 2006-10-01 23:38:21 UTC
Hm, mail-notification also seems to make evolution eat 99% cpu. Disabling it
again for now.

Comment 2 David Woodhouse 2006-10-04 15:52:30 UTC
Ok, the behaviour which caused me to open the bug actually seems to be OK in
practice. It's a little inconsistent and weird but it is relatively useable --
it doesn't actually seem to ignore mails in folders which are currently open;
its definition of 'seen mail' is entirely bizarre, but I'm content with it in
real life when I'm ignoring Evolution, even though I didn't understand it when I
was actively _testing_ its behaviour.

The bug in comment 1 seems to be because we register a callback so that
_whenever_ the gdk main loop is idle, we go poke at Evolution. That isn't a
particularly cunning plan.

Comment 3 David Woodhouse 2006-10-04 15:56:42 UTC
Created attachment 137750 [details]
Workaround

This works around the problem by registering the function to be called every 30
seconds instead of all the time that the app is otherwise idle.

The process is still waking every second, which seems excessive and should be
considered a bug.

Comment 4 Jean-Yves Lefort 2006-10-04 17:07:02 UTC
For evo mailboxes, seen = received after the folder was last poked (IIRC it is
not possible to individually obtain the "read" flag for each evo message).

Regarding the callback, it is executed only once (not repeatedly) for each
queue_check() call, so your patch doesn't make sense (and I don't experience
that high cpu usage here).

Finally, MN is waking up every second indeed, to check if evo is running. Bonobo
does not provide an event-driven interface for checking if a server is up, hence
that poll. I believe that one second is an appropriate interval given that the
task to accomplish (a corba ping or a server activation attempt, depending on
whether evo was running or not the last time) is cheap.

Comment 5 David Woodhouse 2006-10-04 17:30:59 UTC
The patch is just a workaround for the problem I described. I don't know what's
different between your setup and mine, but I definitely see it here on Fedora
Core 6.

If bonobo forces you into polling, then it needs to be fixed. Please make sure a
bug is filed.

You actually shouldn't be polling Evolution either -- you should register with
it and then it should notify _you_ when new mail arrives, or when mail becomes
'seen'.

Comment 6 Thorsten Leemhuis 2006-10-09 15:10:38 UTC
Jean-Yves, so what do we do here to fix that high cpu usage David sees? I can
apply his patch for the Fedora package, but I suspect it's something more
general that sooner or later might hurt other users, too.

Comment 7 Jean-Yves Lefort 2006-10-09 23:25:23 UTC
As I said, I can't reproduce the problem here, so I can't help. I don't
recommend applying the patch since it adds a 30 seconds delay between mail
arrival and its detection without actually fixing the cause of the problem. If I
were you, I'd change the state to "waiting for feedback" and wait for a correct
patch.

Comment 8 David Woodhouse 2006-10-10 06:42:08 UTC
And where would the correct patch come from? I'm not a GUI hacker -- but I've
tried to identify the problem and given a patch which shows where the problem
is, even though I didn't expect it to be a proper fix.

What more information do you need from me?

Comment 9 David Woodhouse 2006-11-15 16:08:08 UTC
Gr. An update in Fedora overrode my package with the workaround and my laptop
started running its fan noisily in my hotel room just after I went to bed. Any
progress on fixing the CPU spinning issue? Does my patch not clearly highlight
the problem?

Comment 10 Jean-Yves Lefort 2006-11-15 17:29:40 UTC
What I said in comment #7 still stands.

Comment 11 David Woodhouse 2006-11-16 13:59:44 UTC
And unfortunately what I said in comment #8 also still stands. I'm not
sufficiently competent with GNOME to provide a proper fix, which is why the
patch I provided was clearly labelled as a 'workaround'.

Nevertheless, it does highlight what seems to be the cause of the problem, and
it is sufficient to actually stop the CPU fan on my laptop from keeping me awake
at night.

I believe that is about as coherent and useful a bug report as any maintainer
can reasonably expect -- and it really ought to be sufficient.

If there's anything more I _can_ realistically provide, please don't hesitate to
ask.

Comment 12 David Woodhouse 2006-11-16 14:27:19 UTC
Does it help if I show a backtrace where the thing keeps _immediately_
re-registering its callback with g_idle_add_locked() ?

Breakpoint 2, mn_g_idle_add_locked (
    function=0x1003be80 <mn_reentrant_mailbox_queue_check_cb>, 
    data=0x100b61c8, lock_func=0x10014ee0 <mn_gdk_threads_enter>, 
    unlock_func=0x10014f20 <mn_gdk_threads_leave>, lock_data=0x0)
    at mn-locked-callback.c:171
171       callback = g_new0(MNLockedCallback, 1);
(gdb) bt
#0  mn_g_idle_add_locked (
    function=0x1003be80 <mn_reentrant_mailbox_queue_check_cb>, 
    data=0x100b61c8, lock_func=0x10014ee0 <mn_gdk_threads_enter>, 
    unlock_func=0x10014f20 <mn_gdk_threads_leave>, lock_data=0x0)
    at mn-locked-callback.c:171
#1  0x1003be64 in mn_reentrant_mailbox_queue_check (self=0x100b61c8)
    at mn-reentrant-mailbox.gob:89
#2  0x1003e83c in mn_evolution_mailbox_listener_cb (
    listener=<value optimized out>, 
    event_name=0x100ebb21 "GNOME/MailNotification/Evolution:folder-changed", 
    any=0x100dafb0, env=<value optimized out>, user_data=<value optimized out>)
    at mn-evolution-mailbox.gob:152
#3  0x100142a0 in mn_locked_bonobo_listener_cb (listener=0x20, 
    event_name=0x100b61c8 "\020\v;\200", any=0x10014ee0, ev=0x10014f20, 
    user_data=<value optimized out>) at mn-locked-callback.c:576
#4  0x0e86ea70 in bonobo_marshal_VOID__STRING_BOXED_BOXED ()
   from /usr/lib/libbonobo-2.so.0
#5  0x0edcd93c in g_closure_invoke () from /lib/libgobject-2.0.so.0
#6  0x0e86d378 in bonobo_closure_invoke_va_list ()
   from /usr/lib/libbonobo-2.so.0
#7  0x0e86d63c in bonobo_closure_invoke () from /usr/lib/libbonobo-2.so.0
#8  0x0e856058 in bonobo_listener_new () from /usr/lib/libbonobo-2.so.0
#9  0x0e870154 in _ORBIT_skel_small_Bonobo_Listener_event ()
   from /usr/lib/libbonobo-2.so.0
#10 0x0f838338 in IOP_start_profiles () from /usr/lib/libORBit-2.so.0
#11 0x0f83f74c in ORBit_OAObject_invoke () from /usr/lib/libORBit-2.so.0
#12 0x0f82887c in ORBit_small_invoke_adaptor () from /usr/lib/libORBit-2.so.0
#13 0x0f83cc88 in ORBit_recv_buffer_return_sys_exception ()
   from /usr/lib/libORBit-2.so.0
#14 0x0f83d2b4 in ORBit_recv_buffer_return_sys_exception ()
   from /usr/lib/libORBit-2.so.0
#15 0x0f81f6d0 in giop_thread_queue_process () from /usr/lib/libORBit-2.so.0
#16 0x0f81fdf4 in giop_init () from /usr/lib/libORBit-2.so.0
#17 0x0f84c480 in link_io_add_watch_fd () from /usr/lib/libORBit-2.so.0
#18 0x0eed7a14 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#19 0x0eedb71c in g_main_context_check () from /lib/libglib-2.0.so.0
#20 0x0eedbb84 in g_main_loop_run () from /lib/libglib-2.0.so.0
#21 0x301ac814 in gtk_main () from /usr/lib/libgtk-x11-2.0.so.0
#22 0x100111e4 in main (argc=0, argv=0x7ff5b5f4) at mn-main.c:471
(gdb) c
Continuing.

Breakpoint 2, mn_g_idle_add_locked (
    function=0x1003be80 <mn_reentrant_mailbox_queue_check_cb>, 
    data=0x100b61c8, lock_func=0x10014ee0 <mn_gdk_threads_enter>, 
    unlock_func=0x10014f20 <mn_gdk_threads_leave>, lock_data=0x0)
    at mn-locked-callback.c:171
171       callback = g_new0(MNLockedCallback, 1);


Comment 13 Jean-Yves Lefort 2006-11-16 14:52:54 UTC
It registers the callback whenever it receives an event from the Evolution MN
plugin (in this case "GNOME/MailNotification/Evolution:folder-changed"). You
need to:

1) Confirm that the folder-changed event is emitted repeatedly (add a printf()
in org_gnome_mail_notification_folder_changed() and observe the output).
2) If confirmed, find out what causes Evolution to repeatedly emit that event.
Maybe some Evolution plugin?

Comment 14 David Woodhouse 2006-11-17 11:42:15 UTC
Thanks for the pointers. 

It seems to be caused by mail-notification itself. When I run the non-modified
version, I see constant emission of folder-changed events for the folders which
mail-notification is configured to watch. With my modified version, the events
are emitted only one set every 30 seconds.
Breakpoint 6, org_gnome_mail_notification_folder_changed (plugin=0x1012b200, 
    folder=0x105d59c8) at mn-evolution-plugin.c:180
180       if (glue_event_sources)
2: folder->uri = 0x10aec550 "imap://dwmw2.org/INBOX"
(gdb) bt
#0  org_gnome_mail_notification_folder_changed (plugin=0x1012b200, 
    folder=0x105d59c8) at mn-evolution-plugin.c:180
#1  0x0ea030e0 in e_plugin_hook_register_type ()
   from /usr/lib/evolution/2.8/libeutil.so.0
#2  0x0ea0272c in e_plugin_invoke () from /usr/lib/evolution/2.8/libeutil.so.0
#3  0x0e9fc5f4 in e_event_get_type () from /usr/lib/evolution/2.8/libeutil.so.0
#4  0x0e9fc7d4 in e_event_emit () from /usr/lib/evolution/2.8/libeutil.so.0
#5  0x0e435804 in mail_note_store ()
   from /usr/lib/evolution/2.8/components/libevolution-mail.so
#6  0x0e437518 in mail_note_store_remove ()
   from /usr/lib/evolution/2.8/components/libevolution-mail.so
#7  0x0e4399dc in mail_msg_free ()
   from /usr/lib/evolution/2.8/components/libevolution-mail.so
#8  0x0eed5258 in g_source_is_destroyed () from /lib/libglib-2.0.so.0
#9  0x0eed7a14 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#10 0x0eedb71c in g_main_context_check () from /lib/libglib-2.0.so.0
#11 0x0eedbb84 in g_main_loop_run () from /lib/libglib-2.0.so.0
#12 0x0e85687c in bonobo_main () from /usr/lib/libbonobo-2.so.0
#13 0x10017054 in ?? ()
#14 0x0f48dd4c in generic_start_main () from /lib/libc.so.6
#15 0x0f48df74 in __libc_start_main () from /lib/libc.so.6
#16 0x00000000 in ?? ()

It's actually stranger than that -- I don't see it emitting folder-changed
events for _every_ folder every time -- visiting a folder (in the Evolution GUI)
makes it less likely that an event will be emitted for that folder. Which is why
it sometimes seems to work OK especially after I visit all four folders which
are configured in mail-notification.

No mail has been arriving during this test, btw -- and no unread mail has been
read. The folder _hasn't_ changed.

Smells like an Evolution bug -- reassigning accordingly. Thanks again for the
assistance in debugging.

Comment 15 David Woodhouse 2006-11-28 17:18:59 UTC
Breakpoint 5, org_gnome_mail_notification_folder_changed (plugin=0x100ad900, 
    folder=0xeb73c848) at mn-evolution-plugin.c:180
180       if (glue_event_sources)
(gdb) bt
#0  org_gnome_mail_notification_folder_changed (plugin=0x100ad900, 
    folder=0xeb73c848) at mn-evolution-plugin.c:180
#1  0x0e763030 in epl_invoke (ep=0x100ad900, 
    name=0x101077c0 "org_gnome_mail_notification_folder_changed", 
    data=0xeb73c848) at e-plugin.c:874
#2  0x0e76267c in e_plugin_invoke (ep=0x100ad900, 
    name=0xeb73c848 "\020\006�@", data=0x0) at e-plugin.c:663
#3  0x0e75c5f4 in emph_event_handle (ee=0x0, item=<value optimized out>, 
    data=<value optimized out>) at e-event.c:407
#4  0x0e75c7d4 in e_event_emit (emp=0x1006a140, id=0xd3367c0 "folder.changed", 
    target=0xeb73c848) at e-event.c:296
#5  0x0d2de8d4 in real_flush_updates (o=<value optimized out>, 
    event_data=<value optimized out>, data=<value optimized out>)
    at mail-folder-cache.c:261
#6  0x0d2e05e8 in do_async_event (mm=<value optimized out>) at mail-mt.c:688
#7  0x0d2e2aac in idle_async_event (mm=0x100ad900) at mail-mt.c:699
#8  0x0ee55258 in g_source_is_destroyed () from /lib/libglib-2.0.so.0
#9  0x0ee57a14 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#10 0x0ee5b71c in g_main_context_check () from /lib/libglib-2.0.so.0
#11 0x0ee5bb84 in g_main_loop_run () from /lib/libglib-2.0.so.0
#12 0x0f72687c in bonobo_main () from /usr/lib/libbonobo-2.so.0
#13 0x10017024 in main (argc=<value optimized out>, argv=0xfffef684)
    at main.c:614


Comment 16 David Woodhouse 2006-11-28 17:26:36 UTC
Not very helpful, I know -- and a breakpoint in camel_object_trigger_event()
doesn't seem to show 'folder_changed' being emitted... having put a breakpoint
in mail-notification at mn_g_idle_add_locked, here's what I see in Evolution
between one trigger of that breakpoint and the next...

I showed a backtrace on the _last_ breakpoint trap before the breakpoint in
mail-notification triggers again. Immediately after that last 'continue' in
Evolution, mail-notification seems to get another 'folder_changed' event.

(gdb) break camel_object_trigger_event
Breakpoint 8 at 0xe6ed8ac: file camel-object.c, line 1454.
(gdb) c
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xead9cd18)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xead9cd18)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xeb7ac690)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xead9cd18)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x101dd2f0, 
    name=0xe680984 "folder_opened", event_data=0x104764e4)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.
Thread f7f18080 >
CamelStore('imap://dwmw2.org/;command=ssh%20-a%20-x%20-C%20baythorne.infradead.org%20exec%20/home/dwmw2/bin/dovecot-imap.sh;use_command;use_ssl=always;check_subscribed'):get_folder('badreply',
0) = 0x104764e4
< f7f18080 >

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x106e2a60, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x1018a9b0, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x106e1dd8, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x106acd44, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) c
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xecc615e0)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xecc617f0)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xecc617f0)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be7c "meta_changed", event_data=0xecc617f0)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x101dd68c, 
    name=0xe680984 "folder_opened", event_data=0x104764e4)
    at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.
Thread f7f18080 >
CamelStore('imap://dwmw2.redhat.com/;check_subscribed;command=/home/dwmw2/bin/connectredhatimap.sh;use_command;use_ssl=always'):get_folder('INBOX',
0) = 0x104764e4
< f7f18080 >

Breakpoint 8, camel_object_trigger_event (vo=0x104764e4, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x106e2a60, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x1018a9b0, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x106e1dd8, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) 
Continuing.

Breakpoint 8, camel_object_trigger_event (vo=0x106acd44, 
    name=0xe70be70 "finalize", event_data=0x0) at camel-object.c:1454
1454            g_return_if_fail (CAMEL_IS_OBJECT (obj));
(gdb) bt
#0  camel_object_trigger_event (vo=0x106acd44, name=0xe70be70 "finalize", 
    event_data=0x0) at camel-object.c:1454
#1  0x0e6ede54 in camel_object_unref (vo=<value optimized out>)
    at camel-object.c:930
#2  0x28048424 in ?? ()
#3  0x0e64b7c4 in camel_folder_finalize (object=<value optimized out>)
    at camel-folder.c:192
#4  0x0e6ede78 in camel_object_unref (vo=<value optimized out>)
    at camel-object.c:935
#5  0x44048282 in ?? ()
#6  0x0cb940e4 in mn_evolution_glue_getUnseenMessages (
    servant=<value optimized out>, folder_uri=<value optimized out>, env=0x388)
    at mn-evolution-glue.gob:113
#7  0x0cb942ec in
_ORBIT_skel_small_GNOME_MailNotification_Evolution_Glue_getUnseenMessages
(_o_servant=0x106acd44, _o_retval=0xfffeefd8, 
    _o_args=<value optimized out>, _o_ctx=0xd8, _o_ev=0x1, 
    _impl_getUnseenMessages=0) at GNOME_MailNotification_Evolution-common.c:16
#8  0x0f7f8338 in IOP_start_profiles () from /usr/lib/libORBit-2.so.0
#9  0x0f7ff74c in ORBit_OAObject_invoke () from /usr/lib/libORBit-2.so.0
#10 0x0f7e887c in ORBit_small_invoke_adaptor () from /usr/lib/libORBit-2.so.0
#11 0x0f7fcc88 in ORBit_recv_buffer_return_sys_exception ()
   from /usr/lib/libORBit-2.so.0
#12 0x0f7fd2b4 in ORBit_recv_buffer_return_sys_exception ()
   from /usr/lib/libORBit-2.so.0
#13 0x0f7df6d0 in giop_thread_queue_process () from /usr/lib/libORBit-2.so.0
#14 0x0f7dfdf4 in giop_init () from /usr/lib/libORBit-2.so.0
#15 0x0f80c480 in link_io_add_watch_fd () from /usr/lib/libORBit-2.so.0
#16 0x0ee57a14 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#17 0x0ee5b71c in g_main_context_check () from /lib/libglib-2.0.so.0
#18 0x0ee5bb84 in g_main_loop_run () from /lib/libglib-2.0.so.0
#19 0x0f72687c in bonobo_main () from /usr/lib/libbonobo-2.so.0
#20 0x10017024 in main (argc=<value optimized out>, argv=0xfffef684)
    at main.c:614
#21 0x0f48dd4c in generic_start_main (main=0x10016d00 <main>, argc=1, 
    ubp_av=0xfffef684, auxvec=0xfffef76c, init=<value optimized out>, 
    fini=<value optimized out>, rtld_fini=<value optimized out>, 
    stack_end=<value optimized out>) at ../csu/libc-start.c:231
#22 0x0f48df74 in __libc_start_main (argc=1, ubp_av=0xfffef684, 
    ubp_ev=<value optimized out>, auxvec=0xfffef76c, 
    rtld_fini=0xffceba0 <_dl_fini>, stinfo=0x10019bb8, 
---Type <return> to continue, or q <return> to quit---
    stack_on_entry=0xfffef670)
    at ../sysdeps/unix/sysv/linux/powerpc/libc-start.c:127
#23 0x00000000 in ?? ()
(gdb) c
Continuing.


Do folder_changed events come from somewhere other than
camel_object_trigger_event() ?

Comment 17 David Woodhouse 2006-11-28 17:50:30 UTC
Answering my own question.... yes, they're generated from real_flush_updates()
as shown in the backtrace in comment #15. Triggered by a call to
flush_updates(), thus...

#0  flush_updates () at mail-folder-cache.c:275
#1  0x0d2dee88 in mail_note_folder (folder=0x10476400)
    at mail-folder-cache.c:524
#2  0x0d2def58 in store_folder_opened (o=<value optimized out>, 
    event_data=0xeb78dec0, data=0x77a344ed) at mail-folder-cache.c:561
#3  0x0e6eda10 in camel_object_trigger_event (vo=0x101dd68c, 
    name=<value optimized out>, event_data=0x10476400) at camel-object.c:1511
#4  0x0e663f58 in camel_store_get_folder (store=0x101dd68c, 
    folder_name=0xead097f1 "INBOX", flags=0, ex=0x0) at camel-store.c:286
#5  0x0d2ecf40 in mail_tool_uri_to_folder (uri=<value optimized out>, flags=0, 
    ex=0x0) at mail-tools.c:333
#6  0x0cb94010 in mn_evolution_glue_getUnseenMessages (
    servant=<value optimized out>, folder_uri=0xeb78dec0 "\r6����S", 
    env=0xfffef0bc) at mn-evolution-glue.gob:61
#7  0x0cb942ec in
_ORBIT_skel_small_GNOME_MailNotification_Evolution_Glue_getUnseenMessages
(_o_servant=0xeb78dec0, _o_retval=0xfffeefd8, 
    _o_args=<value optimized out>, _o_ctx=0xfefefeff, _o_ev=0x33, 
    _impl_getUnseenMessages=0) at GNOME_MailNotification_Evolution-common.c:16
#8  0x0f7f8338 in IOP_start_profiles () from /usr/lib/libORBit-2.so.0
#9  0x0f7ff74c in ORBit_OAObject_invoke () from /usr/lib/libORBit-2.so.0


Comment 18 David Woodhouse 2006-11-28 18:09:32 UTC
This endless loop seems to happen for any folder which isn't currently SELECTed
when I start mail-notification, and it stops when I visit that folder in the
GUI. It starts again when a periodic mail check happens -- even if there are no
new mails.

To reproduce, try setting up mail-notification to monitor more than one folder
in each mailstore, or just view a folder _other_ than your inbox while starting
mail-notification. 

Comment 19 Jean-Yves Lefort 2006-11-28 23:28:20 UTC
This is now crystal clear, good work. I'll probably workaround the API
inconsistency (camel_store_get_folder() emitting a folder_opened event) by
maintaining my own uri->CamelFolder hash table so that I only have to call
mail_tool_uri_to_folder() once.

Comment 20 David Woodhouse 2006-11-30 12:02:47 UTC
Thanks -- I'm glad my debugging was useful to _you_; I was just getting lost in
a twisty maze of Evolution APIs. 

I'll be happy to test a patch when you have one. Is mail-notification in a
version control system somewhere or do you only release tarballs?

Comment 21 Jean-Yves Lefort 2006-12-01 06:07:20 UTC
Created attachment 142541 [details]
potential fix (for 4.0-RC1)

This should fix the problem. Please test.

To answer your question, the MN CVS repository is not publicly accessible.

Comment 22 David Woodhouse 2006-12-01 12:53:27 UTC
(In reply to comment #21)
> This should fix the problem. Please test.

Sorry, it doesn't -- after killing Evolution, bonobo-activation-server and
mail-notification, then starting them all again, I still see the same behaviour.




Comment 23 Jean-Yves Lefort 2006-12-01 13:33:56 UTC
Odd. Please double-check that you're really running the patched version
(including the evo plugin). If you are, then I'll need you to again
find out what is causing the repeated folder_changed events (with an evo bt
similar to the one in comment #17).

I wish I could reproduce this myself, but evo doesn't want to handle my
localhost IMAP test server (it displays "Loading..." forever).

Comment 24 David Woodhouse 2006-12-01 15:44:14 UTC
OK, thanks. That'll probably be Monday now.

Comment 25 David Woodhouse 2006-12-03 16:39:10 UTC
CamelStore('imap://dwmw2.redhat.com/;check_subscribed;command=/home/dwmw2/bin/connectredhatimap.sh;use_command;use_ssl=always'):get_folder('INBOX',
0) = 0xf1c9e204
< f7ef8060 >
b
Breakpoint 1, flush_updates () at mail-folder-cache.c:275
275             if (update_id == -1 && !e_dlist_empty(&updates))
(gdb) bt
#0  flush_updates () at mail-folder-cache.c:275
#1  0x0e0eee88 in mail_note_folder (folder=0xf1c9e204)
    at mail-folder-cache.c:524
#2  0x0e0eef58 in store_folder_opened (o=<value optimized out>, 
    event_data=0x10eb64a8, data=0x77a344ed) at mail-folder-cache.c:561
#3  0x0080da10 in camel_object_trigger_event (vo=0x101dd740, 
    name=<value optimized out>, event_data=0xf1c9e204) at camel-object.c:1511
#4  0x00c03f58 in camel_store_get_folder (store=0x101dd740, 
    folder_name=0x10f1b8d1 "INBOX", flags=0, ex=0x0) at camel-store.c:286
#5  0x0e0fcf40 in mail_tool_uri_to_folder (uri=<value optimized out>, flags=0, 
    ex=0x0) at mail-tools.c:333
#6  0x0d9a5150 in mn_evolution_glue_lookup_folder (
    uri=0x110140e1 "imap://dwmw2.org/INBOX", 
    env=0xfffef0bc) at mn-evolution-glue.gob:165
#7  0x0d9a569c in mn_evolution_glue_getUnseenMessages (
    servant=<value optimized out>, folder_uri=0x10eb64a8 "\016\027��\020�J8", 
    env=0x77a344ed) at mn-evolution-glue.gob:186
#8  0x0d9a5b0c in
_ORBIT_skel_small_GNOME_MailNotification_Evolution_Glue_getUnseenMessages
(_o_servant=0x10eb64a8, _o_retval=0xfffeefd8, 
    _o_args=<value optimized out>, _o_ctx=0xf5e14b8, _o_ev=0x2c, 
    _impl_getUnseenMessages=0) at GNOME_MailNotification_Evolution-common.c:16
#9  0x0f7f8338 in IOP_start_profiles () from /usr/lib/libORBit-2.so.0
#10 0x0f7ff74c in ORBit_OAObject_invoke () from /usr/lib/libORBit-2.so.0
---Type <return> to continue, or q <return> to quit---
#11 0x0f7e887c in ORBit_small_invoke_adaptor () from /usr/lib/libORBit-2.so.0
#12 0x0f7fcc88 in ORBit_recv_buffer_return_sys_exception ()
   from /usr/lib/libORBit-2.so.0
#13 0x0f7fd2b4 in ORBit_recv_buffer_return_sys_exception ()
   from /usr/lib/libORBit-2.so.0
#14 0x0f7df6d0 in giop_thread_queue_process () from /usr/lib/libORBit-2.so.0
#15 0x0f7dfdf4 in giop_init () from /usr/lib/libORBit-2.so.0
#16 0x0f80c480 in link_io_add_watch_fd () from /usr/lib/libORBit-2.so.0
#17 0x0ee57a14 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#18 0x0ee5b71c in g_main_context_check () from /lib/libglib-2.0.so.0
#19 0x0ee5bb84 in g_main_loop_run () from /lib/libglib-2.0.so.0
#20 0x0f72687c in bonobo_main () from /usr/lib/libbonobo-2.so.0
#21 0x10017024 in main (argc=<value optimized out>, argv=0xfffef684)
    at main.c:614

Comment 26 Jean-Yves Lefort 2006-12-03 17:29:23 UTC
Please provide the bt of the second event (type "cont" the first time the
breakpoint is hit, and "bt" the second time).

Comment 27 David Woodhouse 2006-12-03 17:53:04 UTC
I have four watched folders, so I let it happen at least four times before
giving a backtrace. This is about number ten...

(gdb) bt
#0  flush_updates () at mail-folder-cache.c:275
#1  0x0e0eee88 in mail_note_folder (folder=0x10675fc8)
    at mail-folder-cache.c:524
#2  0x0e0eef58 in store_folder_opened (o=<value optimized out>, 
    event_data=0x10987450, data=0x77a344ed) at mail-folder-cache.c:561
#3  0x0080da10 in camel_object_trigger_event (vo=0x101ddae4, 
    name=<value optimized out>, event_data=0x10675fc8) at camel-object.c:1511
#4  0x00c03f58 in camel_store_get_folder (store=0x101ddae4, 
    folder_name=0x106bcd29 "INBOX", flags=0, ex=0x0) at camel-store.c:286
#5  0x0e0fcf40 in mail_tool_uri_to_folder (uri=<value optimized out>, flags=0, 
    ex=0x0) at mail-tools.c:333
#6  0x0d9a5150 in mn_evolution_glue_lookup_folder (
    uri=0x101dd361 "imap://dwmw2.redhat.com/INBOX", 
    env=0xfffef040) at mn-evolution-glue.gob:165
#7  0x0d9a569c in mn_evolution_glue_getUnseenMessages (
    servant=<value optimized out>, 
    folder_uri=0x10987450 "\016\027��\016\027��", env=0x77a344ed)
    at mn-evolution-glue.gob:186


Comment 28 David Woodhouse 2006-12-03 17:59:52 UTC
Breakpoint 1, mn_evolution_glue_lookup_folder (
    uri=0xeb59faf1 "imap://dwmw2.redhat.com/INBOX", 
    env=0xfffef040) at mn-evolution-glue.gob:144
144       private CamelFolder *
(gdb) p folders
$11 = (GHashTable *) 0x106a3020
(gdb) p uri
$12 = 0xeb59faf1 "imap://dwmw2.redhat.com/INBOX"
(gdb) p g_hash_table_lookup(folders, uri)
$13 = 0


Did you ever actually add anything into the hash table?

Comment 29 David Woodhouse 2006-12-03 18:18:40 UTC
Yeah, you did. And then you removed it again immediately. :)

Breakpoint 1, mn_evolution_glue_folder_remove_cb (object=0x10846db8, 
    event_data=0x0, user_data=0xeb4610b8) at mn-evolution-glue.gob:140
140         status = g_hash_table_remove(folders, info->uri);
(gdb) bt
#0  mn_evolution_glue_folder_remove_cb (object=0x10846db8, event_data=0x0, 
    user_data=0xeb4610b8) at mn-evolution-glue.gob:140
#1  0x0080da10 in camel_object_trigger_event (vo=0x10846db8, 
    name=<value optimized out>, event_data=0x0) at camel-object.c:1511
#2  0x0080de54 in camel_object_unref (vo=<value optimized out>)
    at camel-object.c:930
#3  0x40048282 in ?? ()
#4  0x0da15b04 in mn_evolution_glue_getUnseenMessages (
    servant=<value optimized out>, folder_uri=<value optimized out>, 
    env=<value optimized out>) at mn-evolution-glue.gob:238


Comment 30 Jean-Yves Lefort 2006-12-03 18:56:14 UTC
It seems that in your case mail_tool_uri_to_folder() returns a CamelFolder with
refcount 1. That's why it is finalized and removed from the hash table when I do
camel_object_unref().

This would mean that the lifetime of a CamelFolder is unrelated to the lifetime
of the actual folder, unlike what I previously thought.

I'll make another patch.

Comment 31 Jean-Yves Lefort 2006-12-04 10:21:39 UTC
Created attachment 142719 [details]
new fix

What about this one?

Comment 32 David Woodhouse 2006-12-04 11:47:22 UTC
Looks much better; thanks!

Comment 33 Jean-Yves Lefort 2006-12-07 10:49:20 UTC
Fixed in 4.0-RC2. Thanks again for your help.

Comment 34 David Woodhouse 2006-12-08 22:44:29 UTC
(reassigning to mail-notification).

Thanks for the update.

Thorsten, any chance of an updated package with 4.0-RC2, at least in -devel?

Hopefully a real 4.0 release which we can ship in FE6 isn't too far off.

Comment 35 Thorsten Leemhuis 2006-12-09 07:39:57 UTC
(In reply to comment #34)
> Thorsten, any chance of an updated package with 4.0-RC2, at least in -devel?

rc2 was build two days ago for devel, so is on its way already

Comment 36 Thorsten Leemhuis 2007-01-27 14:56:34 UTC
FYI: I'm not going to update to 208774 before 223659 is fixed

Comment 37 Thorsten Leemhuis 2007-02-15 16:36:33 UTC
mail-notification 4.0 which should fix this is now in FE-6


Note You need to log in before you can comment on or make changes to this bug.