The contents of the responses don't get dumped, so I can't see exactly what's going on.

My log shows a lot of requests on SoupSessionSync 1, which are the notification requests, all working fine....


> POST /EWS/Exchange.asmx HTTP/1.1
> Soup-Debug-Timestamp: 1427432847
> Soup-Debug: SoupSessionSync 1 (0x85c33be0), ESoapMessage 33 (0x8656f780), SoupSocket 1 (0x860f2980)
> Host: irsmsx103.ger.corp.intel.com
> User-Agent: Evolution/3.16.0
> Connection: Keep-Alive
> Content-Type: text/xml; charset=utf-8
> Cookie: exchangecookie=efc2f9a704344f14ab27c29eab50795c
> 
> <?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="Exchange2010_SP2"/></SOAP-ENV:Header><SOAP-ENV:Body xmlns:messages="http://schemas.microsoft.com/exchange/services/2006/messages"><messages:GetStreamingEvents xmlns="http://schemas.microsoft.com/exchange/services/2006/types"><messages:SubscriptionIds><SubscriptionId>HABpcnNtc3gxMDMuZ2VyLmNvcnAuaW50ZWwuY29tEAAAAL71bb/YSHhNh+ZLEG1zt4y+kVy7NzbSCA==</SubscriptionId></messages:SubscriptionIds><messages:ConnectionTimeout>10</messages:ConnectionTimeout></messages:GetStreamingEvents></SOAP-ENV:Body></SOAP-ENV:Envelope>


 ... 401 and auth, and then other stuff (qv) before eventually the response comes back... 

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1427433207
< Soup-Debug: ESoapMessage 33 (0x8656f780)
< Cache-Control: private
< Transfer-Encoding: chunked
< Server: Microsoft-IIS/7.5
< X-NoBuffering: 1
< X-AspNet-Version: 2.0.50727
< WWW-Authenticate: Negotiate oYGhMIGeoAMKAQChCwYJKoZIhvcSAQICooGJBIGGYIGDBgkqhkiG9xIBAgICAG90MHKgAwIBBaEDAgEPomYwZKADAgEXol0EW4xC//JktZmclY22EEYResLRU75bGYhigjwcrG8JojOHrSMtz5xRmIFY4mAYzrH1V5rVrPHBmwSoEHs3Cb/B3mKhdBuKG9iRQhJyEj1aKNBCuKH/dqsaZXuu9eM=
< Persistent-Auth: false
< X-Powered-By: ASP.NET
< Date: Fri, 27 Mar 2015 05:07:27 GMT


.... and then we immediately post the next request:

> POST /EWS/Exchange.asmx HTTP/1.1
> Soup-Debug-Timestamp: 1427433207
> Soup-Debug: SoupSessionSync 1 (0x85c33be0), ESoapMessage 34 (0x8656f780), SoupSocket 1 (0x860f2980)
> Host: irsmsx103.ger.corp.intel.com
> User-Agent: Evolution/3.16.0
> Connection: Keep-Alive
> Content-Type: text/xml; charset=utf-8
> Cookie: exchangecookie=efc2f9a704344f14ab27c29eab50795c
> 
> <?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="Exchange2010_SP2"/></SOAP-ENV:Header><SOAP-ENV:Body xmlns:messages="http://schemas.microsoft.com/exchange/services/2006/messages"><messages:GetStreamingEvents xmlns="http://schemas.microsoft.com/exchange/services/2006/types"><messages:SubscriptionIds><SubscriptionId>HABpcnNtc3gxMDMuZ2VyLmNvcnAuaW50ZWwuY29tEAAAAL71bb/YSHhNh+ZLEG1zt4y+kVy7NzbSCA==</SubscriptionId></messages:SubscriptionIds><messages:ConnectionTimeout>10</messages:ConnectionTimeout></messages:GetStreamingEvents></SOAP-ENV:Body></SOAP-ENV:Envelope>
  
... and 401 and auth then:

(evolution:7805): libeews-WARNING **: e-ews-notification.c:617: The specified subscription was not found.

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1427433210
< Soup-Debug: ESoapMessage 34 (0x8656f780)
< Cache-Control: private
< Transfer-Encoding: chunked
< Server: Microsoft-IIS/7.5
< X-NoBuffering: 1
< X-AspNet-Version: 2.0.50727
< WWW-Authenticate: Negotiate oYGhMIGeoAMKAQChCwYJKoZIhvcSAQICooGJBIGGYIGDBgkqhkiG9xIBAgICAG90MHKgAwIBBaEDAgEPomYwZKADAgEXol0EWxLU73ro32GXCZe2rj5E2GqhOBmW8WPzn1kLFMeKgkWmx5OX1X06kWQhBomsnRMjDnqT7aD0alnlSqwJZl2ubXwNwfylVoDxmcJ+HIzTG54Dg530CSnA+5WXgrQ=
< Persistent-Auth: false
< X-Powered-By: ASP.NET
< Date: Fri, 27 Mar 2015 05:13:28 GMT

Created attachment 300423 [details]
EWS_DEBUG log

Here's a full log of what we did from the time ESoapMessage 33 was submitted. We do a SyncFolderHierarchy and a bunch of SyncFolderItems calls, none of which return any changes. Which is fairly much what we do between all the other earlier successful subscription responses. I don't think we did anything to offend the server and make it cancel our subscription ID; I think it just got bored.

And quite frankly, I don't really care why it got cancelled. I really care that once we're told it's expired, we should STOP USING IT! :)

I had to go offline and online again to stop it from eating bandwidth just submitting the same bogus request over and over again, and ignoring the error.

As noted on IRC, even if you can't reproduce the way *I'm* triggering this, you could simulate it and implement/test the error handling path to re-subscribe, just by manually corrupting your own subscription ID after a while.

 static int foo = 5;
 if (foo && !--foo)
    subscription_id[0] = 'x'; /* corrupt it so the server doesn't like it */

I seem to recall another user had the same issue but with a different underlying reason (weren't they actually offline at the time?)

Created attachment 300562 [details] [review]
Constant stream of invalid requests for subscription events

Here is a tentative to fix the problem described by David.

Note: I'd like to have it tested by David before push it to master or 3.16 branch.

Pushed to master (472064f8f6e62b971a32df6c5b6cfdb52eb6b539) and gnome-3-16 (813efa21c9b3399c7b04e5002211181f76425b01).

Thanks for this. It looks like an improvement in the failure mode, but not a real fix. Surely we should resubscribe rather than just stopping the notification altogether?

(In reply to David Woodhouse from comment #6)
> Thanks for this. It looks like an improvement in the failure mode, but not a
> real fix. Surely we should resubscribe rather than just stopping the
> notification altogether?

Sure.
The following patch (0001-*) tries to resubscribe. The others are to "improve" the log situation in the EEwsNotifcation ...

Created attachment 301050 [details] [review]
notification: Try to re-subscribe in case of failure

Created attachment 301051 [details] [review]
Move ews_dump_raw_soup_{request,response} to e-ews-debug.[ch]

Created attachment 301052 [details] [review]
Log the request/response of EEwsNotification

Review of attachment 301050 [details] [review]:

Looks fine, feel free to commit it.

Review of attachment 301051 [details] [review]:

If you do not mind, then just fix the one requested thing.

::: src/server/e-ews-debug.h
@@ +32,3 @@
 							(const gchar *version);
+void		ews_dump_raw_soup_request (SoupMessage *msg);
+void		ews_dump_raw_soup_response (SoupMessage *msg);

It would be nice to change the function prefix, as the functions from here has "e_ews_debug_" prefix.

Review of attachment 301052 [details] [review]:

Looks fine from my point of view. I guess the reason why the logging is not visible is the streaming itself. The SoupLogger (which is attached to the notification session) may prevent to show certain things when it is not enough data or something. Alternatively, as this is running in its own thread, the notification bits can be overlapped/interleaved with other debugging output from the EEwsConnection session.

Created attachment 301054 [details] [review]
Move ews_dump_raw_soup_{request,response} to e-ews-debug.[ch]

Created attachment 301055 [details] [review]
Log the request/response of EEwsNotification

Review of attachment 301054 [details] [review]:

Looks good. If you'd feel like fixing some older coding style issues before committing (like the one marked below, or the other with parameters of the moved functions), then it'll be nice.

::: src/server/e-ews-connection.c
@@ +807,3 @@
 		 * And only if EWS_DEBUG=1, since higher levels will have dumped
 		 * it directly from libsoup anyway. */
+		e_ews_debug_dump_raw_soup_response(msg);

coding style: whitespace missing (I know, it was already there)

Review of attachment 301055 [details] [review]:

Looks fine, feel free to commit.

(In reply to Milan Crha from comment #16)
> Review of attachment 301054 [details] [review] [review]:
> 
> Looks good. If you'd feel like fixing some older coding style issues before
> committing (like the one marked below, or the other with parameters of the
> moved functions), then it'll be nice.
> 
> ::: src/server/e-ews-connection.c
> @@ +807,3 @@
>  		 * And only if EWS_DEBUG=1, since higher levels will have dumped
>  		 * it directly from libsoup anyway. */
> +		e_ews_debug_dump_raw_soup_response(msg);
> 
> coding style: whitespace missing (I know, it was already there)

Sure. I will fix the coding style and push it (without submit a new version here).

All patches were pushed to master.
The first patch was backported to 3.16.