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 785110 - Thread-safety issues with using the same SoupSession synchronously from multiple threads
Thread-safety issues with using the same SoupSession synchronously from multi...
Status: RESOLVED FIXED
Product: libsoup
Classification: Core
Component: HTTP Transport
unspecified
Other Linux
: Normal major
: ---
Assigned To: libsoup-maint@gnome.bugs
libsoup-maint@gnome.bugs
: 796607 (view as bug list)
Depends on:
Blocks:
 
 
Reported: 2017-07-19 08:51 UTC by Sebastian Dröge (slomo)
Modified: 2018-06-21 05:13 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Update get.c to run requests forever from multiple threads (3.89 KB, patch)
2017-07-19 08:53 UTC, Sebastian Dröge (slomo)
none Details | Review

Description Sebastian Dröge (slomo) 2017-07-19 08:51:57 UTC
See attached patch to the get.c and run it like this against the simple_httpd example:

> (update the port)
> ./get -q http://127.0.0.1:36577/get.c

When keeping this running forever, the following warning is printed sometimes

> (get:818): libsoup-WARNING **: (soup-connection.c:660):soup_connection_set_state: runtime check failed: (state == SOUP_CONNECTION_IDLE || state == SOUP_CONNECTION_DISCONNECTED)

When stopping the server while it is running, everything is exploding spectacularly (but not every time):

> (get:3053): GLib-CRITICAL **: g_main_context_ref: assertion 'g_atomic_int_get (&context->ref_count) > 0' failed
> /get.c: 4 Could not connect: Connection refused
> /get.c: 4 Could not connect: Connection refused
> 
> (get:3053): GLib-CRITICAL **: g_main_context_ref: assertion 'g_atomic_int_get (&context->ref_count) > 0' failed
>
> (get:3053): GLib-CRITICAL **: g_main_context_unref: assertion 'g_atomic_int_get (&context->ref_count) > 0' failed
> (get:3116): GLib-GObject-CRITICAL **: g_object_unref: assertion 'G_IS_OBJECT (object)' failed
> fish: “./get -q http://127.0.0.1:36577…” terminated by signal SIGSEGV (Address boundary error)

The same also happens (every few runs) when starting it without the server running at all.

With a single thread (commenting out that for loop), this doesn't seem to happen.
Comment 1 Sebastian Dröge (slomo) 2017-07-19 08:53:01 UTC
Created attachment 355922 [details] [review]
Update get.c to run requests forever from multiple threads
Comment 2 Sebastian Dröge (slomo) 2017-07-19 09:16:01 UTC
Backtrace for the first one:

(get:4696): libsoup-WARNING **: (soup-connection.c:660):soup_connection_set_state: runtime check failed: (state == SOUP_CONNECTION_IDLE || state == SOUP_CONNECTION_DISCONNECTED)

Thread 2 "get" received signal SIGTRAP, Trace/breakpoint trap.
[Switching to Thread 0x7ffff2086700 (LWP 4700)]
_g_log_abort (breakpoint=breakpoint@entry=1) at ././glib/gmessages.c:549
549	././glib/gmessages.c: No such file or directory.
(gdb) thread apply all bt

Thread 7 (Thread 0x7fffebfff700 (LWP 4705))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_mutex_lock_slowpath
    at ././glib/gthread-posix.c line 1313
  • #2 g_mutex_lock
    at ././glib/gthread-posix.c line 1337
  • #3 handler_unref_R
    at ././gobject/gsignal.c line 701
  • #4 handler_match_free1_R
    at ././gobject/gsignal.c line 524
  • #5 signal_handlers_foreach_matched_R
    at ././gobject/gsignal.c line 2797
  • #6 g_signal_handlers_disconnect_matched
    at ././gobject/gsignal.c line 2937
  • #7 soup_auth_manager_request_unqueued
    at soup-auth-manager.c line 786
  • #11 <emit signal ??? on instance 0x55555577d100 [SoupSession]>
    at ././gobject/gsignal.c line 3447
  • #12 soup_session_unqueue_item
    at soup-session.c line 1512
  • #13 soup_session_process_queue_item
    at soup-session.c line 2022
  • #14 soup_message_io_finished
    at soup-message-io.c line 183
  • #15 soup_client_input_stream_close_fn
    at soup-client-input-stream.c line 134
  • #16 g_input_stream_close
    at ././gio/ginputstream.c line 511
  • #17 get_url
    at get.c line 104
  • #18 get_url_loop
    at get.c line 214
  • #19 g_thread_proxy
    at ././glib/gthread.c line 784
  • #20 start_thread
    at pthread_create.c line 333
  • #21 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 2 (Thread 0x7ffff2086700 (LWP 4700))

  • #0 _g_log_abort
    at ././glib/gmessages.c line 549
  • #1 g_logv
    at ././glib/gmessages.c line 1357
  • #2 g_log
    at ././glib/gmessages.c line 1398
  • #3 g_warn_message
    at ././glib/gmessages.c line 2719
  • #4 soup_connection_set_state
    at soup-connection.c line 659
  • #5 soup_connection_get_state
    at soup-connection.c line 636
  • #6 connection_state_changed
    at soup-session.c line 1452
  • #10 <emit signal notify:state on instance 0x7fffd0005690 [SoupConnection]>
    at ././gobject/gsignal.c line 3447
  • #11 g_object_dispatch_properties_changed
    at ././gobject/gobject.c line 1064
  • #12 g_object_notify_queue_thaw
    at ././gobject/gobject.c line 296
  • #13 g_object_thaw_notify
    at ././gobject/gobject.c line 1301
  • #14 soup_connection_set_state
    at soup-connection.c line 676
  • #15 soup_session_unqueue_item
    at soup-session.c line 1477
  • #16 soup_session_process_queue_item
    at soup-session.c line 2022
  • #17 soup_message_io_finished
    at soup-message-io.c line 183
  • #18 soup_client_input_stream_close_fn
    at soup-client-input-stream.c line 134
  • #19 g_input_stream_close
    at ././gio/ginputstream.c line 511
  • #20 get_url
    at get.c line 104
  • #21 get_url_loop
    at get.c line 214
  • #22 g_thread_proxy
    at ././glib/gthread.c line 784
  • #23 start_thread
    at pthread_create.c line 333
  • #24 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Comment 3 Sebastian Dröge (slomo) 2017-07-19 09:19:59 UTC
Backtrace of the second

(get:5665): GLib-CRITICAL **: g_main_context_ref: assertion 'g_atomic_int_get (&context->ref_count) > 0' failed

(get:5665): GLib-CRITICAL **: g_main_context_ref: assertion 'g_atomic_int_get (&context->ref_count) > 0' failed
/get.c: 4 Could not connect: Connection refused

Thread 10 "get" received signal SIGTRAP, Trace/breakpoint trap.
[Switching to Thread 0x7fffea7fc700 (LWP 5677)]
_g_log_abort (breakpoint=breakpoint@entry=1) at ././glib/gmessages.c:549
549	././glib/gmessages.c: No such file or directory.
(gdb) thread apply all bt

Thread 11 (Thread 0x7fffe9084700 (LWP 5678))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 10 (Thread 0x7fffea7fc700 (LWP 5677))

  • #0 _g_log_abort
    at ././glib/gmessages.c line 549
  • #1 g_logv
    at ././glib/gmessages.c line 1357
  • #2 g_log
    at ././glib/gmessages.c line 1398
  • #3 g_return_if_fail_warning
  • #4 g_main_context_ref
    at ././glib/gmain.c line 520
  • #5 soup_socket_set_property
    at soup-socket.c line 340
  • #6 object_set_property
    at ././gobject/gobject.c line 1423
  • #7 g_object_new_internal
    at ././gobject/gobject.c line 1837
  • #8 g_object_new_valist
    at ././gobject/gobject.c line 2042
  • #9 soup_socket_new
    at soup-socket.c line 824
  • #10 soup_connection_connect_sync
    at soup-connection.c line 444
  • #11 get_connection
    at soup-session.c line 1943
  • #12 soup_session_process_queue_item
    at soup-session.c line 1964
  • #13 soup_session_send
    at soup-session.c line 4411
  • #14 get_url
    at get.c line 44
  • #15 get_url_loop
    at get.c line 214
  • #16 g_thread_proxy
    at ././glib/gthread.c line 784
  • #17 start_thread
    at pthread_create.c line 333
  • #18 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 9 (Thread 0x7fffeaffd700 (LWP 5676))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 8 (Thread 0x7fffeb7fe700 (LWP 5675))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 7 (Thread 0x7fffebfff700 (LWP 5674))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 6 (Thread 0x7ffff0883700 (LWP 5673))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 5 (Thread 0x7ffff1084700 (LWP 5672))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 4 (Thread 0x7ffff1885700 (LWP 5671))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 3 (Thread 0x7fffe9885700 (LWP 5670))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 g_thread_proxy
    at ././glib/gthread.c line 784
  • #8 start_thread
    at pthread_create.c line 333
  • #9 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 2 (Thread 0x7ffff2086700 (LWP 5669))

  • #0 _g_log_abort
    at ././glib/gmessages.c line 546
  • #1 g_logv
    at ././glib/gmessages.c line 1357
  • #2 g_log
    at ././glib/gmessages.c line 1398
  • #3 g_return_if_fail_warning
  • #4 g_main_context_ref
    at ././glib/gmain.c line 520
  • #5 soup_socket_set_property
    at soup-socket.c line 340
  • #6 object_set_property
    at ././gobject/gobject.c line 1423
  • #7 g_object_new_internal
    at ././gobject/gobject.c line 1837
  • #8 g_object_new_valist
    at ././gobject/gobject.c line 2042
  • #9 soup_socket_new
    at soup-socket.c line 824
  • #10 soup_connection_connect_sync
    at soup-connection.c line 444
  • #11 get_connection
    at soup-session.c line 1943
  • #12 soup_session_process_queue_item
    at soup-session.c line 1964
  • #13 soup_session_send
    at soup-session.c line 4411
  • #14 get_url
    at get.c line 44
  • #15 get_url_loop
    at get.c line 214
  • #16 g_thread_proxy
    at ././glib/gthread.c line 784
  • #17 start_thread
    at pthread_create.c line 333
  • #18 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 97

Thread 1 (Thread 0x7ffff7fa9e00 (LWP 5665))

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at ././glib/gthread-posix.c line 1395
  • #2 get_connection
    at soup-session.c line 1914
  • #3 soup_session_process_queue_item
    at soup-session.c line 1964
  • #4 soup_session_send
    at soup-session.c line 4411
  • #5 get_url
    at get.c line 44
  • #6 get_url_loop
    at get.c line 214
  • #7 main
    at get.c line 319

Comment 4 Sebastian Dröge (slomo) 2017-07-19 09:26:47 UTC
Some details for the second (the main context has a refcount of 0):

  • #5 soup_socket_set_property
    at soup-socket.c line 340
$1 = (SoupSocketProperties *) 0x7fffd4023ac0
(gdb) print props->async_context
$2 = (GMainContext *) 0x555555776300
(gdb) print *props->async_context
$3 = {
  mutex = {
    p = 0x7fffec0014c0, 
    i = {3959428288, 32767}
  }, 
  cond = {
    p = 0x0, 
    i = {0, 0}
  }, 
  owner = 0x7fffec0049f0, 
  owner_count = 36577, 
  waiters = 0x7fffec004a10, 
  ref_count = 0, 
  sources = 0x0, 
  pending_dispatches = 0xa779c, 
  timeout = 0, 
  next_id = 0, 
  source_lists = 0x0, 
  in_check_or_prepare = 0, 
  need_wakeup = 35, 
  poll_records = 0x1, 
  n_poll_records = 3959436048, 
  cached_poll_array = 0x7fffec004de0, 
  cached_poll_array_size = 1433887552, 
  wakeup = 0x7ffff7b7c6a1, 
  wake_up_rec = {
    fd = 0, 
    events = 0, 
    revents = 0
  }, 
  poll_changed = 0, 
  poll_func = 0x7fffec004a30, 
  time = 36577, 
---Type <return> to continue, or q <return> to quit---
  time_is_fresh = -335525296
}
Comment 5 Sebastian Dröge (slomo) 2017-07-19 09:44:51 UTC
And details for the first (note that this is without stopping the server, so it's probably unexpected indeed that the remote is disconnected... but nonetheless it seems like something that can happen in real situations):

  • #4 soup_connection_set_state
    state=SOUP_CONNECTION_REMOTE_DISCONNECTED) at soup-connection.c:659
659			g_warn_if_fail (state == SOUP_CONNECTION_IDLE ||
(gdb) print state
$1 = SOUP_CONNECTION_REMOTE_DISCONNECTED
Comment 6 Milan Crha 2017-11-15 14:36:18 UTC
Could you try with the patch from bug #762138 comment #3, please? It will address the second part of this bug, but I'm not sure about the other parts. In case it'll fix it for you completely, then this bug can be closed as a duplicate of the older bug report.
Comment 7 Sebastian Dröge (slomo) 2017-11-15 15:44:42 UTC
So far it looks all good here, but I'll let it running over night to be sure.
Comment 8 Sebastian Dröge (slomo) 2017-11-15 15:50:09 UTC
(get:19856): libsoup-WARNING **: (soup-connection.c:670):soup_connection_set_state: runtime check failed: (state == SOUP_CONNECTION_IDLE || state == SOUP_CONNECTION_DISCONNECTED)


Happened again
Comment 9 Milan Crha 2017-11-15 16:26:20 UTC
Thanks for a quick testing. In that case let's keep this for the first issue, the bug #762138 for the second.
Comment 10 Sebastian Dröge (slomo) 2017-11-16 09:14:51 UTC
Yeah, the other bug did not happen over night also. Only the warning from comment 8 quite a few times.
Comment 11 Sebastian Dröge (slomo) 2018-06-18 07:35:28 UTC
*** Bug 796607 has been marked as a duplicate of this bug. ***
Comment 12 Edward Hervey 2018-06-20 11:46:12 UTC
This MR fixed the remaining issue : https://gitlab.gnome.org/GNOME/libsoup/merge_requests/7
Comment 13 Michael Catanzaro 2018-06-20 15:45:16 UTC
After a couple rounds of discussion, I've merged that MR. Glad you found that it fixed bug #762138 as well.

My main concern now is there are still other objects in libsoup which do not use threadsafe refcounting: SoupMessageBody, SoupMessageHeaders, SoupMessageQueue, and SoupServer. Generally, it's expected that structs and objects in GNOME are not threadsafe, except that reffing/unreffing is threadsafe. I understand that SoupMessage and SoupServer are not expected to be threadsafe, unlike SoupSession, and I also understand that using atomic operations can have unexpected costs, but it seems like generally a good idea for ref/unref operations to be atomic unless there is a compelling reason otherwise, right?
Comment 14 Milan Crha 2018-06-20 17:37:23 UTC
(In reply to Michael Catanzaro from comment #13)
>...it seems like generally a good idea for ref/unref operations to be atomic
> unless there is a compelling reason otherwise, right?

+1 from my side. It'll be better if libsoup uses atomic ref/unref on its non-GObject-derived structures. And on those you named I do not think there would be any significant performance impact (those are not ref/unref-ed that often anyway, are they?).
Comment 15 Edward Hervey 2018-06-21 05:13:02 UTC
(In reply to Milan Crha from comment #14)
> (In reply to Michael Catanzaro from comment #13)
> >...it seems like generally a good idea for ref/unref operations to be atomic
> > unless there is a compelling reason otherwise, right?

  right :)

> 
> +1 from my side. It'll be better if libsoup uses atomic ref/unref on its
> non-GObject-derived structures. And on those you named I do not think there
> would be any significant performance impact (those are not ref/unref-ed that
> often anyway, are they?).

  It shouldn't cause a performance impact (we use that same non-gobject-based-but-atomic-refcounted technique in GStreamer and it hasn't been an issue :) ).

  I'll have a look and propose new issue and merge-request for those.