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 342545 - exchange-connector crashes caused by libsoup
exchange-connector crashes caused by libsoup
Status: RESOLVED FIXED
Product: libsoup
Classification: Core
Component: HTTP Transport
2.2.x
Other All
: Normal critical
: ---
Assigned To: Dan Winship
Dan Winship
: 322901 (view as bug list)
Depends on:
Blocks:
 
 
Reported: 2006-05-22 06:22 UTC by Wang Xin
Modified: 2006-06-07 18:08 UTC
See Also:
GNOME target: ---
GNOME version: 2.13/2.14


Attachments
patch (2.30 KB, patch)
2006-05-25 21:49 UTC, Dan Winship
none Details | Review

Description Wang Xin 2006-05-22 06:22:35 UTC
Steps to reproduce:
1. Use a e-mail account(not exchange account) send a e-mail to exchange account.
2. Select exchange account and click Receive button repeatly.
3. Sometimes exchange-connector would crash.


Stack trace:
The stack trace then exchange-connector crashes:

** (evolution-exchange-storage:6075): WARNING **: Unexpected error 0 (null) from
POLL

(evolution-exchange-storage:6075): GLib-GObject-WARNING **: instance of invalid
non-instantiatable type `account-removed'

Program received signal SIGSEGV, Segmentation fault.

Thread 1098457760 (LWP 6075)

  • #0 io_read
    at soup-message-io.c line 551
  • #1 IA__g_cclosure_marshal_VOID__VOID
    at gmarshal.c line 77
  • #2 IA__g_closure_invoke
    at gclosure.c line 490
  • #3 signal_emit_unlocked_R
    at gsignal.c line 2438
  • #4 IA__g_signal_emit_valist
    at gsignal.c line 2197
  • #5 IA__g_signal_emit
    at gsignal.c line 2241
  • #6 socket_read_watch
    at soup-socket.c line 1069
  • #7 g_io_unix_dispatch
    at giounix.c line 162
  • #8 IA__g_main_context_dispatch
    at gmain.c line 1916
  • #9 g_main_context_iterate
    at gmain.c line 2547
  • #10 IA__g_main_loop_run
    at gmain.c line 2751
  • #11 bonobo_main
    from /home/jedy/garnome/lib/libbonobo-2.so.0
  • #12 main
    at main.c line 238
  • #0 new_iostate
    at soup-message-io.c line 747
  • #1 soup_message_io_client
    at soup-message-io.c line 774
  • #2 soup_message_send_request_internal
    at soup-message-client-io.c line 185
  • #3 send_request
    at soup-connection.c line 769
  • #4 send_request
    at soup-connection-ntlm.c line 218
  • #5 soup_connection_send_request
    at soup-connection.c line 788
  • #6 run_queue
    at soup-session-async.c line 147
  • #7 connection_closed
    at soup-session-async.c line 83
  • #8 IA__g_cclosure_marshal_VOID__VOID
    at gmarshal.c line 77
  • #9 IA__g_closure_invoke
    at gclosure.c line 490
  • #10 signal_emit_unlocked_R
    at gsignal.c line 2438
  • #11 IA__g_signal_emit_valist
    at gsignal.c line 2197
  • #12 IA__g_signal_emit
    at gsignal.c line 2241
  • #13 soup_connection_disconnect
    at soup-connection.c line 680
  • #14 clear_current_request
    at soup-connection.c line 404
  • #15 soup_connection_release
    at soup-connection.c line 821
  • #16 soup_message_io_stop
    at soup-message-io.c line 135
  • #17 io_cleanup
    at soup-message-io.c line 80
  • #18 soup_message_io_finished
    at soup-message-io.c line 149
  • #19 io_read
    at soup-message-io.c line 701
  • #20 IA__g_cclosure_marshal_VOID__VOID
    at gmarshal.c line 77
  • #21 IA__g_closure_invoke
    at gclosure.c line 490
  • #22 signal_emit_unlocked_R
    at gsignal.c line 2438
  • #23 IA__g_signal_emit_valist
    at gsignal.c line 2197
  • #24 IA__g_signal_emit
    at gsignal.c line 2241
  • #25 socket_read_watch
    at soup-socket.c line 1069
  • #26 g_io_unix_dispatch
    at giounix.c line 162
  • #27 IA__g_main_context_dispatch
    at gmain.c line 1916
  • #28 g_main_context_iterate
    at gmain.c line 2547
  • #29 IA__g_main_loop_run
    at gmain.c line 2751
  • #30 bonobo_main
    from /home/jedy/garnome/lib/libbonobo-2.so.0
  • #31 main
    at main.c line 238

which indicate when io_cleanup called on msg(0x80cd128), a new_iostate is called
on the same msg(0x80cd128).Is this correct? I think maybe this is the problem.
Comment 1 Wang Xin 2006-05-25 10:08:55 UTC
Sorry, forget something when input "Other information".
New "Other information" attached as follows.


Other information:
Everytime this crash bug happens, i found line 746, 747 of new_iostate
    746: 	if (priv->io_data)
    747:		io_cleanup (msg);
will be executed and when i set a breakpoint at line 747 i got a stack trace:

  • #0 new_iostate
    at soup-message-io.c line 747
  • #1 soup_message_io_client
    at soup-message-io.c line 774
  • #2 soup_message_send_request_internal
    at soup-message-client-io.c line 185
  • #3 send_request
    at soup-connection.c line 769
  • #4 send_request
    at soup-connection-ntlm.c line 218
  • #5 soup_connection_send_request
    at soup-connection.c line 788
  • #6 run_queue
    at soup-session-async.c line 147
  • #7 connection_closed
    at soup-session-async.c line 83
  • #8 IA__g_cclosure_marshal_VOID__VOID
    at gmarshal.c line 77
  • #9 IA__g_closure_invoke
    at gclosure.c line 490
  • #10 signal_emit_unlocked_R
    at gsignal.c line 2438
  • #11 IA__g_signal_emit_valist
    at gsignal.c line 2197
  • #12 IA__g_signal_emit
    at gsignal.c line 2241
  • #13 soup_connection_disconnect
    at soup-connection.c line 680
  • #14 clear_current_request
    at soup-connection.c line 404
  • #15 soup_connection_release
    at soup-connection.c line 821
  • #16 soup_message_io_stop
    at soup-message-io.c line 135
  • #17 io_cleanup
    at soup-message-io.c line 80
  • #18 soup_message_io_finished
    at soup-message-io.c line 149
  • #19 io_read
    at soup-message-io.c line 701
  • #20 IA__g_cclosure_marshal_VOID__VOID
    at gmarshal.c line 77
  • #21 IA__g_closure_invoke
    at gclosure.c line 490
  • #22 signal_emit_unlocked_R
    at gsignal.c line 2438
  • #23 IA__g_signal_emit_valist
    at gsignal.c line 2197
  • #24 IA__g_signal_emit
    at gsignal.c line 2241
  • #25 socket_read_watch
    at soup-socket.c line 1069
  • #26 g_io_unix_dispatch
    at giounix.c line 162
  • #27 IA__g_main_context_dispatch
    at gmain.c line 1916
  • #28 g_main_context_iterate
    at gmain.c line 2547
  • #29 IA__g_main_loop_run
    at gmain.c line 2751
  • #30 bonobo_main
    from /home/jedy/garnome/lib/libbonobo-2.so.0
  • #31 main
    at main.c line 238

which indicates when io_cleanup called on msg(0x80cd128), a new_iostate is
called on the same msg(0x80cd128).Is this correct? I think maybe this is the problem.
Comment 2 Wang Xin 2006-05-25 10:59:49 UTC
We found that it is because when msg->status_code is 440(E2K_HTTP_TIMEOUT), in io_read the status_code callback function fba_timeout_handler registered by exchange-connector will be called and it requeues the msg(set msg->stauts to SOUP_MESSAGE_STATUS_QUEUED). When soup_message_io_finished is called by io_read, soup_message_io_finished will call soup_connection_disconnect(indicate by the trace in "Other information") which will sigal a disconnect singal on the connction. And when the signal handler connection_closed is callded for this signal, the msg will be sent again. But when leaving soup_message_io_finished, the reference count of msg is 0. So when io_read is called on the msg when reply arrived from exchange server, a segment fault occurs.

But the most amazing thing is that, in most case, even though disconnect signal is signaled by soup_connection_disconnect, but connection_closed will not be called. So not every msg whose status_code is 440 will cause the bug, but only the one leads connection_closed called.
Comment 3 Wang Xin 2006-05-25 11:19:12 UTC
I think what exchange-connector wants to do when connction timeout is to resend the message, this is resonable. In this case, soup_message_restarted in soup_message_io_finished should be called and resend the message. But now, the message is resend when io_cleanup is called, and after that the msg->status is running and soup_message_restarted would not be called but soup_message_finished instead.

I changed

static void
soup_message_io_finished (SoupMessage *msg)
{
	g_object_ref (msg);
	io_cleanup (msg);
	if (SOUP_MESSAGE_IS_STARTING (msg))
		soup_message_restarted (msg);
	else
		soup_message_finished (msg);
	g_object_unref (msg);
}

to

static void
soup_message_io_finished (SoupMessage *msg)
{
	g_object_ref (msg);
	if (SOUP_MESSAGE_IS_STARTING (msg))
		soup_message_restarted (msg);
	else
		soup_message_finished (msg);
	io_cleanup (msg);
	g_object_unref (msg);
}

to ensure the message would be restarted before io_cleanup, so it would be send in io_cleanup. It works fine now, but i am not sure if this is correct or not.
Comment 4 Dan Winship 2006-05-25 21:49:03 UTC
Created attachment 66227 [details] [review]
patch

You can't move the io_cleanup call because then if the message starts getting
re-sent by the soup_message_restarted() call, then io_cleanup() will free the
*new* iostate rather than the *old* iostate.

Fundamentally, the problem seems to be that:

    (a) soup_session_requeue_message sets the message status to QUEUED,
        but leaves its iostate unchanged

    (b) soup-session-async.c:run_queue() believes it can send off any
        QUEUED message whenever it wants to, regardless of its iostate.

Ideally I think we'd want a new SoupMessageStatus value "REQUEUED", but that
would break API/ABI.

The attached patch makes run_queue() refuse to requeue messages that are still
being processed by soup-message-io. I think this should fix the problem. Can
you test it and get back to me?
Comment 5 Wang Xin 2006-05-26 02:22:32 UTC
I tested the patch, and I can not reproduce the bug any more. It works fine.
Comment 6 Dan Winship 2006-05-26 14:43:15 UTC
Great. Thanks for figuring this out.

Fixed in CVS, and will be released in 2.2.93 by Monday (for GNOME 2.14.2)
Comment 7 Dan Winship 2006-06-07 18:08:24 UTC
*** Bug 322901 has been marked as a duplicate of this bug. ***