Hmm, "after some time" sounds too vague. From the log I see that this happened in ebews_start_gal_sync(). The first critical warning is there, because priv->oab_url is NULL. Looking into its usages in e-book-backend-ews.c, I see that  this can happen either from beginning, or after dispose, thus it feels like you got out lucky, and you ews book backend was reincarnated after the first call to dispose. If you want, I can workaround this by moving the priv->oab_url free into finalize.

(In reply to comment #1)
> Hmm, "after some time" sounds too vague.

Yeah, if I knew more I'd have said more :)

Happened again today; the GAL just stopped responding. Again, I was actually trying to send an email and didn't stop to debug it. Killing e-addr-factory and restarting it made things work again.

I'd been running from a terminal with EWS_DEBUG=2, in fact, and I have all its output. It has my personal addressbook in it (full contents thereof, it seems, for some reason) so I won't just post it. 

But basically it just stopped doing *anything* on around Jun 19th and I never noticed. That part of the log goes something like this...

> GET /OAB/ca12e903-ba6c-424b-bdb9-06189f712b3f/afe69797-f428-4fb8-bc52-b5bdb3559d8a-data-635.lzx HTTP/1.1
> Soup-Debug-Timestamp: 1371672948
> Soup-Debug: SoupSessionAsync 1 (0x7f9814039770), SoupMessage 1 (0x7f97fc007160), SoupSocket 1 (0x7f9800004310), restarted
> Host: irsmsx101.ger.corp.intel.com
> User-Agent: libews/0.1
> Connection: Keep-Alive
> Authorization: NTLM TlRMTVNTUAADAAAAGAAYAFIAAAAYABgAagAAAAMAAwBAAAAACAAIAEMAAAAHAAcASwAAAAAAAAAAAAAAggEIAEdFUmR3b29kaG91VU5LTk9XTgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHpzjQEuNIO6y3kp+qCadMT5dTekNgcHqw==
  
< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1371672996
< Soup-Debug: SoupMessage 1 (0x7f97fc007160)
< Content-Type: application/octet-stream
< Last-Modified: Wed, 19 Jun 2013 18:29:37 GMT
< Accept-Ranges: bytes
< ETag: "ae473f41a6dce1:0"
< Server: Microsoft-IIS/7.5
< Persistent-Auth: true
< X-Powered-By: ASP.NET
< Date: Wed, 19 Jun 2013 20:15:48 GMT
< Content-Length: 30527734
  
OAL file downloaded /home/dwmw2/.cache/evolution/addressbook/1371672602.19736.0@shinybook.infradead.org/afe69797-f428-4fb8-bc52-b5bdb3559d8a-data-635.lzx
OAL file decompressed /home/dwmw2/.cache/evolution/addressbook/1371672602.19736.0@shinybook.infradead.org/Global Address List-635.oab 
Ewsgal: Removing old gal 
Ewsgal: Replacing old gal with new gal contents in db 
Total records is 216671 
GAL adding contacts, percent complete : 0 
GAL adding contacts, percent complete : 0 
 ...
GAL adding contacts, percent complete : 99 
GAL adding contacts, percent complete : 99 
GAL adding contacts, percent complete : 100 
Ews gal: sync successful complete 
> POST /EWS/Exchange.asmx HTTP/1.1
> Soup-Debug-Timestamp: 1371682298
> Soup-Debug: SoupSessionAsync 1 (0x7f9814039000), ESoapMessage 4 (0x7f98140414b0), SoupSocket 2 (0x7c8ef0)
> Host: irsmsx105.ger.corp.intel.com
> User-Agent: Evolution/3.8.4
> Connection: Keep-Alive
> Content-Type: text/xml; charset=utf-8
> Authorization: NTLM TlRMTVNTUAABAAAABoIIAAAAAAAAAAAAAAAAAAAAAAAAAAAAMAAAAAAAAAAwAAAA
> 
> <?xml version="1.0" encoding="UTF-8" standalone="no"?>
> <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" xmlns:SOAP-ENC="http://schemas.xmlsoap.org/soap/encoding/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"><SOAP-ENV:Header><types:RequestServerVersion xmlns:types="http://schemas.microsoft.com/exchange/services/2006/types" Version="Exchange2007_SP1"/></SOAP-ENV:Header><SOAP-ENV:Body xmlns:messages="http://schemas.microsoft.com/exchange/services/2006/messages"><messages:GetFolder xmlns="http://schemas.microsoft.com/exchange/services/2006/types"><messages:FolderShape><BaseShape>Default</BaseShape></messages:FolderShape><messages:FolderIds><DistinguishedFolderId Id="inbox"/></messages:FolderIds></messages:GetFolder></SOAP-ENV:Body></SOAP-ENV:Envelope>
  
< HTTP/1.1 401 Unauthorized
< Soup-Debug-Timestamp: 1371682298
< Soup-Debug: ESoapMessage 4 (0x7f98140414b0)
< Server: Microsoft-IIS/7.5
< Set-Cookie: exchangecookie=5ddfadc0d713421e854d0f304e798942; expires=Thu, 19-Jun-2014 22:51:38 GMT; path=/; HttpOnly
< WWW-Authenticate: NTLM TlRMTVNTUAACAAAAAwADADgAAAAGgokCIcfo/2OriSQAAAAAAAAAALQAtAA7AAAABgGxHQAAAA9HRVICAAYARwBFAFIAAQASAEkAUgBTAE0AUwBYADEAMAA1AAQAJABnAGUAcgAuAGMAbwByAHAALgBpAG4AdABlAGwALgBjAG8AbQADADgASQBSAFMATQBTAFgAMQAwADUALgBnAGUAcgAuAGMAbwByAHAALgBpAG4AdABlAGwALgBjAG8AbQAFABwAYwBvAHIAcAAuAGkAbgB0AGUAbAAuAGMAbwBtAAcACAB4AZmOP23OAQAAAAA=
< WWW-Authenticate: Negotiate
< X-Powered-By: ASP.NET
< Date: Wed, 19 Jun 2013 22:51:37 GMT
< Content-Length: 0
  
> POST /EWS/Exchange.asmx HTTP/1.1
> Soup-Debug-Timestamp: 1371682298
> Soup-Debug: SoupSessionAsync 1 (0x7f9814039000), ESoapMessage 4 (0x7f98140414b0), SoupSocket 2 (0x7c8ef0), restarted
> Host: irsmsx105.ger.corp.intel.com
> User-Agent: Evolution/3.8.4
> Connection: Keep-Alive
> Content-Type: text/xml; charset=utf-8
> Content-Length: 842
> Authorization: NTLM TlRMTVNTUAADAAAAGAAYAFIAAAAYABgAagAAAAMAAwBAAAAACAAIAEMAAAAHAAcASwAAAAAAAAAAAAAAggEIAEdFUmR3b29kaG91VU5LTk9XTgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAJz8bQWgnCc/oZ02pj+W3GfGXkNGckCUng==
> 
> <?xml version="1.0" encoding="UTF-8" standalone="no"?>
> <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" xmlns:SOAP-ENC="http://schemas.xmlsoap.org/soap/encoding/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"><SOAP-ENV:Header><types:RequestServerVersion xmlns:types="http://schemas.microsoft.com/exchange/services/2006/types" Version="Exchange2007_SP1"/></SOAP-ENV:Header><SOAP-ENV:Body xmlns:messages="http://schemas.microsoft.com/exchange/services/2006/messages"><messages:GetFolder xmlns="http://schemas.microsoft.com/exchange/services/2006/types"><messages:FolderShape><BaseShape>Default</BaseShape></messages:FolderShape><messages:FolderIds><DistinguishedFolderId Id="inbox"/></messages:FolderIds></messages:GetFolder></SOAP-ENV:Body></SOAP-ENV:Envelope>
  
< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1371682298
< Soup-Debug: ESoapMessage 4 (0x7f98140414b0)
< Cache-Control: private
< Transfer-Encoding: chunked
< Content-Type: text/xml; charset=utf-8
< Server: Microsoft-IIS/7.5
< Set-Cookie: exchangecookie=690d842f35ff4b6eb53120c5bc8a7270; expires=Thu, 19-Jun-2014 22:51:38 GMT; path=/; HttpOnly
< X-AspNet-Version: 2.0.50727
< Persistent-Auth: true
< X-Powered-By: ASP.NET
< Date: Wed, 19 Jun 2013 22:51:37 GMT
  
<?xml version="1.0" encoding="utf-8"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Header>
    <h:ServerVersionInfo xmlns:h="http://schemas.microsoft.com/exchange/services/2006/types" xmlns="http://schemas.microsoft.com/exchange/services/2006/types" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" MajorVersion="14" MinorVersion="3" MajorBuildNumber="123" MinorBuildNumber="3" Version="Exchange2010_SP2"/>
  </s:Header>
  <s:Body xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema">
    <m:GetFolderResponse xmlns:m="http://schemas.microsoft.com/exchange/services/2006/messages" xmlns:t="http://schemas.microsoft.com/exchange/services/2006/types">
      <m:ResponseMessages>
        <m:GetFolderResponseMessage ResponseClass="Success">
          <m:ResponseCode>NoError</m:ResponseCode>
          <m:Folders>
            <t:Folder>
              <t:FolderId Id="AQMkADQyOWY3OTVmLWEzODYtNDI5NS1hZmE2LThiMjhmYWRjOGQ0NwAuAAADC1lfIzWaQkSVrsfRo+opswEAMVKzN7WM30+n53HCmWrAXwAAASz7bwAAAA==" ChangeKey="AQAAABYAAACnCUASyhvDT7JwON9NYNl4AAAvqfIT"/>
              <t:DisplayName>Inbox</t:DisplayName>
              <t:TotalCount>1410</t:TotalCount>
              <t:ChildFolderCount>0</t:ChildFolderCount>
              <t:UnreadCount>702</t:UnreadCount>
            </t:Folder>
          </m:Folders>
        </m:GetFolderResponseMessage>
      </m:ResponseMessages>
    </m:GetFolderResponse>
  </s:Body>
</s:Envelope>
^C

That's when I killed and restarted it, and it started working again.

If(when) this happens again, I suppose I should attach with gdb and try to work out wtf it thinks it's doing. Anything in particular I should be looking for? Or debugging I should add to my build before I reproduce?

Perhaps it's some locking issue, with a lock that doesn't get freed when we do a GAL update?
[dwmw2@shinybook evolution-ews]$ EWS_DEBUG=2 /usr/libexec/evolution-addressbook-factory -r

Note: my latest log doesn't seem to contain any of those critical warnings that I originally encountered. They may not be relevant.

Note #2: It is now June 24th. The previous e-addr-factory hadn't done anything useful since June 19th. Not even on the 'personal addresbook' folder.

If the whole addressbook factory is stuck, then yes, get a backtrace of the factory, maybe it'll show what it is waiting for.

Hm, there is weirdness here. I reply to an email, and my company GAL isn't working but personal (non-EWS) address book *is* for autocompletion.

Reply to the same mail again, and a *different* composer window does have a functional GAL. And in Evolution's addressbook pane, the GAL is also working.

I'll keep this offending composer window open... how can I debug this some more?

There is weirdness here. That composer window started working again. Closer investigation of the dbus-monitor traces shows that 6 address book views were being created and running to completion, but the seventh (presumably the GAL) was never completing and was being cancelled.

So maybe the GAL was just being *really* slow for some reason?

It's hard to do any diagnosis because as soon as I move the mouse outside the composer window, Evolution stops the searches. But in the failing case, if I type a name that exists in a personal address book *and* the GAL, the personal matches *were* turning up. What should have happened then? The GAL matches would be added to the dropdown list, when they eventually turned up? Perhaps I should have waited for even longer, without moving the mouse?

Perhaps the issue here is just that there's no user feedback while queries are outstanding? That and the automatic cancellation if I *try* to let it run and do something else in the meantime?

Hm, I've definitely managed to reproduce it just *stopping*. Even the EWS addressbooks in Evolutions 'contacts' pane were not working, although the local ones were. I had fallen off the VPN and rejoined with a different IP address, in case that's relevant. So existing connections will have died. But libsoup should handle that transparently, surely?

I stupidly managed to kill it while I was trying to get a proper backtrace. All I have is this incomplete version...

Program received signal SIGINT, Interrupt.
0x000000360baeab6d in poll () at ../sysdeps/unix/syscall-template.S:81
81	T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)
(gdb) bt

+ Trace 232214

Note that there's most of a 't a a bt' in the above, which is hidden by bugzilla's "helpful" rendition of the content which shows only one thread.

There are a bunch of threads all stuck at:

+ Trace 232215

That's within libsoup's get_connection(). It finds an *existing* connection for the host in question, then waits for it to become available.

Why it doesn't time out and make a new connection, I don't know.

Why the existing connection never becomes available, I also don't know.

Dan?

(In reply to comment #11)
> That's within libsoup's get_connection(). It finds an *existing* connection for
> the host in question, then waits for it to become available.

No, it finds that there are no existing connections that are idle, but too many in-use connections for it to be able to create a new one, so it waits until the situation changes. Unfortunately, due to a bug, the situation never changes (because the connections that are allegedly idle actually aren't).

Anyway, this is probably bug 703463, which is fixed in master. I was going to try to fix bug 698912 (which is apparently different, but probably closely related) before building new packages, but maybe I should just put out this fix now...

That's great, thanks. I'll build libsoup with that change and see if I can reproduce.

Btw, if you're building new packages then including a fix for bug 703186 would be much appreciated. I know I said I'd help look at a test case for it... maybe *after* the meeting in, $DEITY, 45 minutes where I lament how little of $DAYJOB I've managed to achieve this week...

Just wondering, should this be moved to libsoup, where the actual fix was done?

Sure. David, did we ever confirm that the libsoup fix fixed it?

Yes, I think so. For my users I've built a libsoup package with the patches for bug 703463 and bug 703186, and I've not seen this issue for a while. I think that's the last outstanding rebuilt Fedora package in my repo for now, so getting an update would be much appreciated.

*** This bug has been marked as a duplicate of bug 703463 ***