After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 777161 - Deadlock under soup_auth_manager_use_auth()
Deadlock under soup_auth_manager_use_auth()
Status: RESOLVED OBSOLETE
Product: libsoup
Classification: Core
Component: Misc
2.57.x
Other Linux
: Normal normal
: ---
Assigned To: libsoup-maint@gnome.bugs
libsoup-maint@gnome.bugs
Depends on:
Blocks:
 
 
Reported: 2017-01-12 09:05 UTC by Hussam Al-Tayeb
Modified: 2018-09-21 16:27 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
proposed patch (4.91 KB, patch)
2017-01-12 10:24 UTC, Milan Crha
reviewed Details | Review

Description Hussam Al-Tayeb 2017-01-12 09:05:35 UTC
I put my computer to hibernation at night and resume in the morning. I have a pppoe connection which times out after I resume and gets redialed (pppd).

In the meantime, it seems libsoup/evolution gets confused and stops being able to read/update calendars till I "pkill evolution-calendar-factory"

A backtrace log using gdb reveals the following:

[New LWP 23946]
[New LWP 23947]
[New LWP 23948]
[New LWP 23949]
[New LWP 23952]
[New LWP 23953]
[New LWP 23965]
[New LWP 23967]
[New LWP 23970]
[New LWP 24083]
[New LWP 24085]
[New LWP 24088]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
0x00007f3be2526b99 in syscall () from /usr/lib/libc.so.6

Thread 13 (Thread 0x7f3b9effd700 (LWP 24088))

  • #0 syscall
  • #1 g_mutex_lock_slowpath
    at gthread-posix.c line 1313
  • #2 g_mutex_lock
    at gthread-posix.c line 1337
  • #3 soup_auth_manager_use_auth
    at soup-auth-manager.c line 809
  • #4 caldav_ensure_bearer_auth_usage
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 357
  • #5 caldav_setup_bearer_auth
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 385
  • #6 soup_authenticate_bearer
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1138
  • #7 soup_authenticate
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1188
  • #8 ffi_call_unix64
  • #9 ffi_call
  • #10 g_cclosure_marshal_generic_va
    at gclosure.c line 1604
  • #11 _g_closure_invoke_va
    at gclosure.c line 867
  • #12 g_signal_emit_valist
    at gsignal.c line 3300
  • #13 g_signal_emit
    at gsignal.c line 3447
  • #14 ffi_call_unix64
  • #15 ffi_call
  • #16 g_cclosure_marshal_generic_va
    at gclosure.c line 1604
  • #17 _g_closure_invoke_va
    at gclosure.c line 867
  • #18 g_signal_emit_valist
    at gsignal.c line 3300
  • #19 g_signal_emit
    at gsignal.c line 3447
  • #20 auth_got_headers
    at soup-auth-manager.c line 626
  • #24 <emit signal ??? on instance 0x7f3bb000c460 [SoupMessage]>
    at gsignal.c line 3447
  • #25 soup_message_got_headers
    at soup-message.c line 1128
  • #26 io_read
    at soup-message-io.c line 706
  • #27 io_run_until
    at soup-message-io.c line 982
  • #28 io_run
    at soup-message-io.c line 1053
  • #29 soup_message_io_client
    at soup-message-io.c line 1233
  • #30 soup_message_send_request
    at soup-message-client-io.c line 161
  • #31 soup_connection_send_request
    at soup-connection.c line 708
  • #32 soup_session_send_queue_item
    at soup-session.c line 1326
  • #33 soup_session_process_queue_item
    at soup-session.c line 1987
  • #34 soup_session_real_send_message
    at soup-session.c line 2218
  • #35 send_and_handle_redirection
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1284
  • #36 check_calendar_changed_on_server
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1547
  • #37 caldav_synchronize_cache
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 2325
  • #38 caldav_synch_slave_loop
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 2645
  • #39 g_thread_proxy
    at gthread.c line 784
  • #40 start_thread
  • #41 clone

Thread 12 (Thread 0x7f3ba4ff9700 (LWP 24085))

  • #0 syscall
  • #1 g_mutex_lock_slowpath
    at gthread-posix.c line 1313
  • #2 g_mutex_lock
    at gthread-posix.c line 1337
  • #3 soup_auth_manager_use_auth
    at soup-auth-manager.c line 809
  • #4 caldav_ensure_bearer_auth_usage
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 357
  • #5 caldav_setup_bearer_auth
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 385
  • #6 soup_authenticate_bearer
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1138
  • #7 soup_authenticate
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1188
  • #8 ffi_call_unix64
  • #9 ffi_call
  • #10 g_cclosure_marshal_generic_va
    at gclosure.c line 1604
  • #11 _g_closure_invoke_va
    at gclosure.c line 867
  • #12 g_signal_emit_valist
    at gsignal.c line 3300
  • #13 g_signal_emit
    at gsignal.c line 3447
  • #14 ffi_call_unix64
  • #15 ffi_call
  • #16 g_cclosure_marshal_generic_va
    at gclosure.c line 1604
  • #17 _g_closure_invoke_va
    at gclosure.c line 867
  • #18 g_signal_emit_valist
    at gsignal.c line 3300
  • #19 g_signal_emit
    at gsignal.c line 3447
  • #20 auth_got_headers
    at soup-auth-manager.c line 626
  • #24 <emit signal ??? on instance 0x7f3bac020650 [SoupMessage]>
    at gsignal.c line 3447
  • #25 soup_message_got_headers
    at soup-message.c line 1128
  • #26 io_read
    at soup-message-io.c line 706
  • #27 io_run_until
    at soup-message-io.c line 982
  • #28 io_run
    at soup-message-io.c line 1053
  • #29 soup_message_io_client
    at soup-message-io.c line 1233
  • #30 soup_message_send_request
    at soup-message-client-io.c line 161
  • #31 soup_connection_send_request
    at soup-connection.c line 708
  • #32 soup_session_send_queue_item
    at soup-session.c line 1326
  • #33 soup_session_process_queue_item
    at soup-session.c line 1987
  • #34 soup_session_real_send_message
    at soup-session.c line 2218
  • #35 send_and_handle_redirection
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1284
  • #36 check_calendar_changed_on_server
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1547
  • #37 caldav_synchronize_cache
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 2325
  • #38 caldav_synch_slave_loop
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 2645
  • #39 g_thread_proxy
    at gthread.c line 784
  • #40 start_thread
  • #41 clone

Thread 11 (Thread 0x7f3b9ffff700 (LWP 24083))

  • #0 syscall
  • #1 g_mutex_lock_slowpath
    at gthread-posix.c line 1313
  • #2 g_mutex_lock
    at gthread-posix.c line 1337
  • #3 soup_auth_manager_use_auth
    at soup-auth-manager.c line 809
  • #4 caldav_ensure_bearer_auth_usage
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 357
  • #5 caldav_setup_bearer_auth
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 385
  • #6 soup_authenticate_bearer
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1138
  • #7 soup_authenticate
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1188
  • #8 ffi_call_unix64
  • #9 ffi_call
  • #10 g_cclosure_marshal_generic_va
    at gclosure.c line 1604
  • #11 _g_closure_invoke_va
    at gclosure.c line 867
  • #12 g_signal_emit_valist
    at gsignal.c line 3300
  • #13 g_signal_emit
    at gsignal.c line 3447
  • #14 ffi_call_unix64
  • #15 ffi_call
  • #16 g_cclosure_marshal_generic_va
    at gclosure.c line 1604
  • #17 _g_closure_invoke_va
    at gclosure.c line 867
  • #18 g_signal_emit_valist
    at gsignal.c line 3300
  • #19 g_signal_emit
    at gsignal.c line 3447
  • #20 auth_got_headers
    at soup-auth-manager.c line 626
  • #24 <emit signal ??? on instance 0x7f3bb8023670 [SoupMessage]>
    at gsignal.c line 3447
  • #25 soup_message_got_headers
    at soup-message.c line 1128
  • #26 io_read
    at soup-message-io.c line 706
  • #27 io_run_until
    at soup-message-io.c line 982
  • #28 io_run
    at soup-message-io.c line 1053
  • #29 soup_message_io_client
    at soup-message-io.c line 1233
  • #30 soup_message_send_request
    at soup-message-client-io.c line 161
  • #31 soup_connection_send_request
    at soup-connection.c line 708
  • #32 soup_session_send_queue_item
    at soup-session.c line 1326
  • #33 soup_session_process_queue_item
    at soup-session.c line 1987
  • #34 soup_session_real_send_message
    at soup-session.c line 2218
  • #35 send_and_handle_redirection
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1284
  • #36 check_calendar_changed_on_server
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 1547
  • #37 caldav_synchronize_cache
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 2325
  • #38 caldav_synch_slave_loop
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 2645
  • #39 g_thread_proxy
    at gthread.c line 784
  • #40 start_thread
  • #41 clone

Thread 1 (Thread 0x7f3be3c4f740 (LWP 23944))

  • #0 syscall
  • #1 g_cond_wait
    at gthread-posix.c line 1395
  • #2 soup_session_real_flush_queue
    at soup-session.c line 2499
  • #3 soup_session_abort
    at soup-session.c line 2531
  • #4 caldav_notify_online_cb
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/backends/caldav/e-cal-backend-caldav.c line 5450
  • #8 <emit signal notify:online on instance 0x14261f0 [ECalBackendCalDAV]>
    at gsignal.c line 3447
  • #9 g_object_dispatch_properties_changed
    at gobject.c line 1064
  • #10 g_object_notify_by_spec_internal
    at gobject.c line 1157
  • #11 g_object_notify
    at gobject.c line 1205
  • #12 e_backend_set_online
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/libebackend/e-backend.c line 804
  • #13 backend_network_monitor_can_reach_cb
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/libebackend/e-backend.c line 112
  • #14 g_task_return_now
    at gtask.c line 1145
  • #15 complete_in_idle_cb
    at gtask.c line 1159
  • #16 g_main_dispatch
    at gmain.c line 3203
  • #17 g_main_context_dispatch
    at gmain.c line 3856
  • #18 g_main_context_iterate
    at gmain.c line 3929
  • #19 g_main_loop_run
    at gmain.c line 4125
  • #20 main
    at /home/hussam/cache/gnome/evolution-data-server/src/evolution-data-server/src/calendar/libedata-cal/evolution-calendar-factory-subprocess.c line 217

Comment 1 Milan Crha 2017-01-12 10:23:33 UTC
The backtrace shows that one thread (the main thread) is in the soup_session_abort() call, which several other threads are in soup_auth_manager_use_auth() waiting for some lock to be acquired.


The problem is that the auth_got_headers() at soup-auth-manager.c line 626 holds the private structure lock, when the CalDAV signal handler calls the soup_auth_manager_use_auth() at soup-auth-manager.c line 809, which tries to acquire the same lock at the same thread.
Comment 2 Milan Crha 2017-01-12 10:24:42 UTC
Created attachment 343350 [details] [review]
proposed patch

Either make the lock recursive (what this patch does), or free the lock when the outer callbacks are going to be called.
Comment 3 Hussam Al-Tayeb 2017-01-16 11:49:48 UTC
Hi. I've been using this patch for the last few days and I haven't seen any deadlocks in evolution calendar backend since.
Comment 4 Milan Crha 2017-01-16 13:14:27 UTC
This doesn't seem to be new in libsoup, thus it would be nice to get the proposed patch (if accepted) also to any future stable release. Thanks in advance.
Comment 5 Dan Winship 2017-02-20 21:04:45 UTC
Comment on attachment 343350 [details] [review]
proposed patch

I don't think a recursive mutex is the right solution. (Recursive mutexes are almost never the right solution.) But I haven't looked enough to know if there are issues with just releasing the lock around the signal emission.
Comment 6 Milan Crha 2017-04-04 12:32:01 UTC
> (Recursive mutexes are almost never the right solution.)

Right, I understand, but here the problem is that the signal emission means calling anything outside libsoup control, and users (like me), can do weird things, which look correct though. Thus I chose to use recursive mutex, also because signal emission is synchronous, not asynchronous, thus if anything needs to modify the libsoup object state can do it only in the same thread, which is perfectly fine limitation (not a limitation as such, from my point of view).

There are more users hitting this issue, which prevents them to use Google calendars from evolution-data-server.

Could you reconsider this, please?
Comment 7 Dan Winship 2017-04-04 14:48:05 UTC
Using a recursive mutex and allowing re-entrant calls only works if the internal SoupAuthManager state is guaranteed to be fully self-consistent at the point when the signal is emitted, and if the function emitting the signal doesn't assume that the state of the auth-manager after the signal emission is the same as the state before the signal emission.

But if all of that is true, then we don't need a recursive mutex; you can just release the mutex around the signal emission instead.

So, if you can prove that a recursive mutex will work, then you don't need it.
Comment 8 Milan Crha 2017-04-05 07:35:43 UTC
Yes, the recursive mutex works, but look at the backtrace in comment #0. Three threads are inside auth_got_headers() and the main thread is in soup_session_abort(). Thus the two can interleave. I do not know libsoup internals and I see that soup_session_abort() waits on a GCond, not on the mutex, thus this can be irrelevant.

One thing I didn't think of before, is it "legal" to call soup_auth_manager_use_auth() inside the SoupSession::authenticate signal? If it's wrong, then the problem is in CalDAV code instead. The SoupSession::authenticate is called with already chosen 'auth', thus it can be eventually wrong to try to change it. Maybe? I do not know how much sense it would be to try to switch authentication method during authentication. It surely makes sense when libsoup begins for example Basic authentication and I realize in "authenticate" handler that the correct authentication method is OAuth (or any other), in which case I want to change it, without a round trip of cancelling current message send and re-issuing it with different authentication object. Again, I can be wrong. Please, correct me, if I am.

I also noticed that I call soup_auth_manager_use_auth() with the same 'auth' object as the one passed to "authenticate" callback, thus it is a nonsense in this case. And the three threads are all working with different SoupSession object.

I'm more and more convinced that it's me doing things wrong, not libsoup. What do you think, Dan?
Comment 9 Milan Crha 2017-04-10 07:33:58 UTC
I made a change which will not call soup_auth_manager_use_auth() when inside the "authenticate" signal handler for the time being. If it's the right thing to do, then we can move this bug report back to evolution-data-server and close it.

Created commit_a40d3cd in eds master (3.25.1+) [1]
Created commit_d0b262d in eds gnome-3-24 (3.24.1+)

[1] https://git.gnome.org/browse/evolution-data-server/commit/?id=a40d3cd
Comment 10 Dan Winship 2017-04-10 14:03:32 UTC
I haven't had a chance to figure this out completely, but if you aren't allowed to call use_auth() from inside an authenticate callback, then that at least needs to be documented (and there should probably be a return-if-fail). So leave this bug open anyway.
Comment 11 GNOME Infrastructure Team 2018-09-21 16:27:47 UTC
-- GitLab Migration Automatic Message --

This bug has been migrated to GNOME's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.gnome.org/GNOME/libsoup/issues/99.