Page MenuHomePhabricator

Unhandled exceptions when doing remote requests
Open, HighPublic17 Story Points

Description

There's a few unhandled issues with remote fetches which cause the entire stalk to bomb out it's match.

Resolution plan

Ideally, we should capture this and alert on it as if it was a true match; with proper note that it's a "match" because an error was encountered, not a true match.

Wherever possible, if the error can be "ignored" (ie the presense of the error has no impact on the overall outcome of the match) then we shouldn't flag this as a match-due-to-error. I'd hope that the first pass of the "two-pass approach" this would be smart enough to detect it, but we might want to refactor how the overall matching is done.

To do this, we need to replace the current bool? Match(rc, bool) and bool Match(rc) calls with something capable of returning an object encapsulating a match. I suggest:

  • bool isMatch = false
  • bool resolved = false
  • Exception error = null
NOTE: What about an enum? There's a lot of invalid combinations with this approach which an enum would solve.

This will allow for reporting a match status along with an error status. If error is not-null, then the exception has had an impact on the parse result. Valid states will thus be:

isMatchresolvederrorMeaning
falsefalsenullMatch has not yet been checked
falsetruenullMatch has been checked, and it has failed the match
truetruenullMatch has been checked, and it has passed the match
truetrueObjectMatch has been checked, an error was encountered, and the match could not be discarded.

Estimate

  • Write the new object and resolution handling: 2
  • Retrofit every stalk node to generate a match status: 4
  • Overall match resolution: 2
  • Test updates: 7?
  • Handling of error conditions: 2

Error logs

2018-07-11 19:49:38,047 [15] DEBUG Stwalkerster.IrcClient.IrcClient.Wikimedia.NetworkClient.Inbound [(null)] - :rc-pmtpa!~rc-pmtpa@special.user PRIVMSG #en.wikipedia :14[[07Special:Log/newusers14]]4 create210 02 5* 03EAM1974 5*  10created new account User:KDavies4StateAuditor

2018-07-11 19:49:38,048 [15] INFO  EyeInTheSky.Services.MediaWikiApi [(null)] - Getting groups for EAM1974 from webservice

2018-07-11 19:49:38,049 [15] DEBUG EyeInTheSky.Services.WebServiceClient [(null)] - Requesting https://en.wikipedia.org/w/api.php?action=query&list=users&usprop=groups&ususers=EAM1974&format=xml

2018-07-11 19:49:38,325 [15] ERROR EyeInTheSky.Services.ChannelConfiguration [(null)] - Error during evaluation of stalk acc-create2@##stwalkerster-creations
System.Net.WebException: The remote server returned an error: (503) Backend fetch failed.
  at System.Net.HttpWebRequest+<GetResponseFromData>d__247.MoveNext () [0x00152] in <fc308f916aec4e4283e0c1d4b761760a>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Net.HttpWebRequest+<RunWithTimeoutWorker>d__244`1[T].MoveNext () [0x000ba] in <fc308f916aec4e4283e0c1d4b761760a>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Net.HttpWebRequest.GetResponse () [0x00013] in <fc308f916aec4e4283e0c1d4b761760a>:0 
  at EyeInTheSky.Services.WebServiceClient.DoApiCall (System.Collections.Specialized.NameValueCollection query) [0x000a8] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Services.MediaWikiApi.GetUserGroups (System.String user) [0x00091] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.RecentChange.GetUserGroups () [0x00028] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.StalkNodes.UserGroupStalkNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0000d] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.StalkNodes.AndNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0001d] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc) [0x0001a] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Model.ComplexStalk.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc) [0x0000a] in <8cc47d86cf7646219263717e78dfb108>:0 
  at EyeInTheSky.Services.ChannelConfiguration+<MatchStalks>d__1.MoveNext () [0x000da] in <8cc47d86cf7646219263717e78dfb108>:0
2019-03-24 23:56:34,896 [14] INFO  Stwalkerster.Bot.MediaWikiLib.Services.MediaWikiApi [(null)] - Getting groups for Tassedethe from webservice

2019-03-24 23:56:34,898 [14] DEBUG Stwalkerster.Bot.MediaWikiLib.Services.WebServiceClient [(null)] - Requesting https://en.wikipedia.org/w/api.php?action=query&list=users&usprop=groups&ususers=Tassedethe&format=xml

2019-03-24 23:56:34,931 [14] ERROR EyeInTheSky.Services.ChannelConfiguration [(null)] - Error during evaluation of stalk blp-death@##eyeinthesky
System.Net.WebException: Error getting response stream (ReadDoneAsync2): ReceiveFailure
  at System.Net.WebResponseStream.InitReadAsync (System.Threading.CancellationToken cancellationToken) [0x000f3] in <99508e34019346e68bffacfcecbd997e>:0 
  at System.Net.WebOperation.Run () [0x001d9] in <99508e34019346e68bffacfcecbd997e>:0 
  at System.Net.WebCompletionSource`1[T].WaitForCompletion () [0x00094] in <99508e34019346e68bffacfcecbd997e>:0 
  at System.Net.HttpWebRequest.RunWithTimeoutWorker[T] (System.Threading.Tasks.Task`1[TResult] workerTask, System.Int32 timeout, System.Action abort, System.Func`1[TResult] aborted, System.Threading.CancellationTokenSource cts) [0x000f8] in <99508e34019346e68bffacfcecbd997e>:0 
  at System.Net.HttpWebRequest.GetResponse () [0x00016] in <99508e34019346e68bffacfcecbd997e>:0 
  at Stwalkerster.Bot.MediaWikiLib.Services.WebServiceClient.DoApiCall (System.Collections.Specialized.NameValueCollection query, System.String endpoint, System.String userAgent, System.Net.CookieContainer cookieJar, System.Boolean post) [0x00108] in <0b64a129aef64e0b859212b46f3a152a>:0 
  at Stwalkerster.Bot.MediaWikiLib.Services.WebServiceClient.DoApiCall (System.Collections.Specialized.NameValueCollection query, System.String endpoint, System.String userAgent) [0x00009] in <0b64a129aef64e0b859212b46f3a152a>:0 
  at Stwalkerster.Bot.MediaWikiLib.Services.MediaWikiApi.GetUserGroups (System.String user) [0x000af] in <0b64a129aef64e0b859212b46f3a152a>:0 
  at EyeInTheSky.Model.RecentChange.GetUserGroups () [0x00028] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.UserGroupStalkNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0000d] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.OrNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0001d] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.NotNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00006] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.AndNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0001d] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.ExternalNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00006] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc) [0x0001a] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Model.ComplexStalk.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc) [0x0000a] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0 
  at EyeInTheSky.Services.ChannelConfiguration+<MatchStalks>d__1.MoveNext () [0x000fe] in <f0a6b4dbd60a4ba8bb6fe04431201150>:0
2019-06-27 02:50:35,865 [13] ERROR EyeInTheSky.Services.ChannelConfiguration [(null)] - Error during evaluation of stalk blp-death@##eyeinthesky
System.Net.WebException: Error: SecureChannelFailure (Unable to read data from the transport connection: Connection reset by peer.) ---> System.IO.IOException: Unable to read data from the transport connection: Connection reset by peer. ---> System.Net.Sockets.SocketException: Connection reset by peer
  at System.Net.Sockets.Socket.EndReceive (System.IAsyncResult asyncResult) [0x00012] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.Sockets.NetworkStream.EndRead (System.IAsyncResult asyncResult) [0x00057] in <e8eb3d7a311640f484845e45cbec8973>:0 
   --- End of inner exception stack trace ---
  at System.Net.Sockets.NetworkStream.EndRead (System.IAsyncResult asyncResult) [0x0009b] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.IO.Stream+<>c.<BeginEndReadAsync>b__43_1 (System.IO.Stream stream, System.IAsyncResult asyncResult) [0x00000] in <6649516e5b3542319fb262b421af0adb>:0 
  at System.Threading.Tasks.TaskFactory`1+FromAsyncTrimPromise`1[TResult,TInstance].Complete (TInstance thisRef, System.Func`3[T1,T2,TResult] endMethod, System.IAsyncResult asyncResult, System.Boolean requiresSynchronization) [0x00000] in <6649516e5b3542319fb262b421af0adb>:0 
--- End of stack trace from previous location where exception was thrown ---

  at Mono.Net.Security.MobileAuthenticatedStream.InnerRead (System.Boolean sync, System.Int32 requestedSize, System.Threading.CancellationToken cancellationToken) [0x00104] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at Mono.Net.Security.AsyncProtocolRequest.InnerRead (System.Threading.CancellationToken cancellationToken) [0x000ac] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at Mono.Net.Security.AsyncProtocolRequest.ProcessOperation (System.Threading.CancellationToken cancellationToken) [0x00093] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at Mono.Net.Security.AsyncProtocolRequest.StartOperation (System.Threading.CancellationToken cancellationToken) [0x0008b] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at Mono.Net.Security.MobileAuthenticatedStream.ProcessAuthentication (System.Boolean runSynchronously, Mono.Net.Security.MonoSslAuthenticationOptions options, System.Threading.CancellationToken cancellationToken) [0x00252] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at Mono.Net.Security.MonoTlsStream.CreateStream (System.Net.WebConnectionTunnel tunnel, System.Threading.CancellationToken cancellationToken) [0x00126] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.WebConnection.CreateStream (System.Net.WebOperation operation, System.Boolean reused, System.Threading.CancellationToken cancellationToken) [0x001ba] in <e8eb3d7a311640f484845e45cbec8973>:0 
   --- End of inner exception stack trace ---
  at System.Net.WebConnection.CreateStream (System.Net.WebOperation operation, System.Boolean reused, System.Threading.CancellationToken cancellationToken) [0x0021a] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.WebConnection.InitConnection (System.Net.WebOperation operation, System.Threading.CancellationToken cancellationToken) [0x00141] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.WebOperation.Run () [0x0009a] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.WebCompletionSource`1[T].WaitForCompletion () [0x00094] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.HttpWebRequest.RunWithTimeoutWorker[T] (System.Threading.Tasks.Task`1[TResult] workerTask, System.Int32 timeout, System.Action abort, System.Func`1[TResult] aborted, System.Threading.CancellationTokenSource cts) [0x000f8] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at System.Net.HttpWebRequest.GetResponse () [0x00016] in <e8eb3d7a311640f484845e45cbec8973>:0 
  at Stwalkerster.Bot.MediaWikiLib.Services.WebServiceClient.DoApiCall (System.Collections.Specialized.NameValueCollection query, System.String endpoint, System.String userAgent, System.Net.CookieContainer cookieJar, System.Boolean post) [0x00108] in <0b64a129aef64e0b859212b46f3a152a>:0 
  at Stwalkerster.Bot.MediaWikiLib.Services.WebServiceClient.DoApiCall (System.Collections.Specialized.NameValueCollection query, System.String endpoint, System.String userAgent) [0x00009] in <0b64a129aef64e0b859212b46f3a152a>:0 
  at Stwalkerster.Bot.MediaWikiLib.Services.MediaWikiApi.PageIsInCategory (System.String page, System.String category) [0x0007a] in <0b64a129aef64e0b859212b46f3a152a>:0 
  at EyeInTheSky.Model.RecentChange.PageIsInCategory (System.String category) [0x00043] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Model.StalkNodes.InCategoryNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0000d] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Model.StalkNodes.AndNode.DoMatch (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x0001d] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc, System.Boolean forceMatch) [0x00007] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Model.StalkNodes.BaseNodes.StalkNode.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc) [0x0001a] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Model.ComplexStalk.Match (EyeInTheSky.Model.Interfaces.IRecentChange rc) [0x0000a] in <ece8623a40144a9bb69a2c46d01952ca>:0 
  at EyeInTheSky.Services.ChannelConfiguration+<MatchStalks>d__1.MoveNext () [0x000fe] in <ece8623a40144a9bb69a2c46d01952ca>:0

Details

Event Timeline

swalker renamed this task from EITS Error Log to System.Net.WebException: The remote server returned an error: (503) Backend fetch failed..Jul 23 2018, 2:22 PM
swalker triaged this task as High priority.
swalker shifted this object from the Restricted Space space to the S1 Default space.
swalker updated the task description. (Show Details)
swalker moved this task from Backlog to Bugs on the EyeInTheSky board.
swalker merged a task: Unknown Object (Maniphest Task).Aug 28 2018, 9:27 AM
swalker merged a task: Unknown Object (Maniphest Task).Feb 20 2019, 12:56 PM
swalker renamed this task from System.Net.WebException: The remote server returned an error: (503) Backend fetch failed. to Unhandled exceptions when doing remote requests.Mar 25 2019, 9:55 AM
swalker updated the task description. (Show Details)
swalker merged a task: Unknown Object (Maniphest Task).Mar 25 2019, 9:57 AM
swalker merged a task: Unknown Object (Maniphest Task).May 27 2019, 10:15 AM
swalker merged a task: Unknown Object (Maniphest Task).
stwalkerster merged a task: Unknown Object (Maniphest Task).Jul 13 2019, 9:43 PM
stwalkerster merged a task: Unknown Object (Maniphest Task).Aug 1 2019, 7:46 PM
swalker set the point value for this task to 17.Aug 6 2019, 2:16 PM
swalker updated the task description. (Show Details)
stwalkerster merged a task: Unknown Object (Maniphest Task).Aug 18 2019, 1:40 PM
swalker merged a task: Unknown Object (Maniphest Task).Aug 26 2019, 3:19 PM