I’ve seeing a strange issue whereby a SPA & .NET Framework project using NTLM auth fails with an “error occurred outside services” message, apparently because of duplicate keys being added into cookie collections, deep in the Auth framework?
The error I get is (with different keys being the cause - see attached files):
**Uncaught Exception Error occurred outside of Services: ArgumentException: Item has already been added. Key in dictionary: 'AUTH_PASSWORD' Key being added: 'AUTH_PASSWORD'**
The thing is, the exception affects different endpoints calls, and seems to occur basically when a new user hits our SPA and several API calls fire to load up various data to render the UI.
I can replicate this by
visiting our app (NTLM auth)
clearing out all cookies
going to some other website
return to our app
The SPA will send 3+ API calls, and almost always fails on some endpoint, which oddly sends back a 200 HttpCode, but crashes the SPA because the data returned isnt JSON, its the error above. And I end up with a stack trace like:
2018-10-16 05:03:03.0391||ERROR|ServiceStackHost|Error occured while Processing Request: Item has already been added. Key in dictionary: 'CERT_KEYSIZE' Key being added: 'CERT_KEYSIZE' System.ArgumentException: Item has already been added. Key in dictionary: 'CERT_KEYSIZE' Key being added: 'CERT_KEYSIZE'
at System.Collections.Hashtable.Insert(Object key, Object nvalue, Boolean add)
at System.Collections.Specialized.NameObjectCollectionBase.BaseAdd(String name, Object value)
at System.Web.HttpRequest.FillInServerVariablesCollection()
at System.Web.HttpServerVarsCollection.Populate()
at System.Web.HttpServerVarsCollection.Get(String name)
at ServiceStack.Auth.AspNetWindowsAuthProvider.Authenticate(IServiceBase authService, IAuthSession session, Authenticate request)
at ServiceStack.Auth.AuthenticateService.Post(Authenticate request)
at ServiceStack.Auth.AspNetWindowsAuthProvider.PreAuthenticate(IRequest req, IResponse res)
at ServiceStack.AuthenticateAttribute.PreAuthenticate(IRequest req, IEnumerable`1 authProviders)
at ServiceStack.AuthenticateAttribute.<ExecuteAsync>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersSingleAsync>d__322.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersAsync>d__321.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.Host.Handlers.GenericHandler.<ProcessRequestAsync>d__12.MoveNext()
Has anyone seen this before, and got any suggestions for a fix?
Its worth mentioning that after this initial crashed endpoint (which unfortunately breaks our SPA), if the user does a page refresh, it seems that everything works fine… but the sporadic breaks during the initial page load mean we are stuck. (and cannot say “hey guys, just refresh”).
Also, there is another error that occurs in tandem,
2018-10-16 05:37:45.6721||ERROR|ServiceStackHost|Error occured while Processing Request: Index was outside the bounds of the array. System.IndexOutOfRangeException: Index was outside the bounds of the array.
at System.Collections.Generic.Dictionary`2.Insert(TKey key, TValue value, Boolean add)
at ServiceStack.SessionExtensions.CreateTemporarySessionId(IResponse res, IRequest req)
at ServiceStack.SessionExtensions.GenerateNewSessionCookies(IRequest req, IAuthSession session)
at ServiceStack.Auth.AuthenticateService.Authenticate(Authenticate request, String provider, IAuthSession session, IAuthProvider oAuthConfig)
at ServiceStack.Auth.AuthenticateService.Post(Authenticate request)
at ServiceStack.Auth.AspNetWindowsAuthProvider.PreAuthenticate(IRequest req, IResponse res)
at ServiceStack.AuthenticateAttribute.PreAuthenticate(IRequest req, IEnumerable`1 authProviders)
at ServiceStack.AuthenticateAttribute.<ExecuteAsync>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersSingleAsync>d__322.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersAsync>d__321.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.Host.Handlers.GenericHandler.<ProcessRequestAsync>d__12.MoveNext()
2018-10-16 05:12:40.3322||ERROR|ServiceStackHost|Error occured while Processing Request: Item has already been added. Key in dictionary: 'ss-id' Key being added: 'ss-id' System.ArgumentException: Item has already been added. Key in dictionary: 'ss-id' Key being added: 'ss-id'
at System.Collections.Hashtable.Insert(Object key, Object nvalue, Boolean add)
at System.Collections.Specialized.NameObjectCollectionBase.BaseAdd(String name, Object value)
at System.Web.HttpResponse.SetCookie(HttpCookie cookie)
at ServiceStack.Host.Cookies.AddSessionCookie(String cookieName, String cookieValue, Nullable`1 secureOnly)
at ServiceStack.SessionExtensions.CreateTemporarySessionId(IResponse res, IRequest req)
at ServiceStack.SessionExtensions.GenerateNewSessionCookies(IRequest req, IAuthSession session)
at ServiceStack.Auth.AuthenticateService.Authenticate(Authenticate request, String provider, IAuthSession session, IAuthProvider oAuthConfig)
at ServiceStack.Auth.AuthenticateService.Post(Authenticate request)
at ServiceStack.Auth.AspNetWindowsAuthProvider.PreAuthenticate(IRequest req, IResponse res)
at ServiceStack.AuthenticateAttribute.PreAuthenticate(IRequest req, IEnumerable`1 authProviders)
at ServiceStack.AuthenticateAttribute.<ExecuteAsync>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersSingleAsync>d__322.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersAsync>d__321.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.Host.Handlers.GenericHandler.<ProcessRequestAsync>d__12.MoveNext()
2018-10-16 05:12:40.3322||ERROR|AspNetRequest|ServiceStack.Host.AspNet.AspNetRequest System.ArgumentException: Item has already been added. Key in dictionary: 'ss-id' Key being added: 'ss-id'
at System.Collections.Hashtable.Insert(Object key, Object nvalue, Boolean add)
at System.Collections.Specialized.NameObjectCollectionBase.BaseAdd(String name, Object value)
at System.Web.HttpResponse.SetCookie(HttpCookie cookie)
at ServiceStack.Host.Cookies.AddSessionCookie(String cookieName, String cookieValue, Nullable`1 secureOnly)
at ServiceStack.SessionExtensions.CreateTemporarySessionId(IResponse res, IRequest req)
at ServiceStack.SessionExtensions.GenerateNewSessionCookies(IRequest req, IAuthSession session)
at ServiceStack.Auth.AuthenticateService.Authenticate(Authenticate request, String provider, IAuthSession session, IAuthProvider oAuthConfig)
at ServiceStack.Auth.AuthenticateService.Post(Authenticate request)
at ServiceStack.Auth.AspNetWindowsAuthProvider.PreAuthenticate(IRequest req, IResponse res)
at ServiceStack.AuthenticateAttribute.PreAuthenticate(IRequest req, IEnumerable`1 authProviders)
at ServiceStack.AuthenticateAttribute.<ExecuteAsync>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersSingleAsync>d__322.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.ServiceStackHost.<ApplyRequestFiltersAsync>d__321.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at ServiceStack.Host.Handlers.GenericHandler.<ProcessRequestAsync>d__12.MoveNext()
2018-10-16 05:12:40.3322||ERROR|AspNetRequest|api.service.messages.messages.ie2e.productgroups.ListProductGroupsRequest ServiceStack.HttpError: Unauthorized
2018-10-16 05:12:40.3422||ERROR|ServiceStackHost|ServiceBase<TRequest>::Service Exception ServiceStack.HttpError: Unauthorized
No, it’s actually the default servicestack implementation for .net framework (4.6), I had to revert back to Framework (political reason, not technical).
This is going to sound silly, but I think it’s a kind of threading/data access issue, where a couple different requests are trying to access/initialise values in a user-specific dictionary which isn’t locked/threadsafe?. When we fire off multiple parallel requests at the same time (think “list user details” & “load user tasks” & “load config settings” in parallel for a faster initial UI render) for a “newly encountered” user (ie no cookies), we can reproduce this pretty much every time.
When I tried a dirty hack so that, for any initial page load, i fire off one and one only request initially, and when that returns, fire off as many as I want in parallel… Everything seems to work fine.
It’s as though that first, single request initialises the newly encountered users’ cookies collections, without collisions, and then all the latter requests run smoothly because they probably don’t try to reinitialize the cookies.
So, it’s actually possible that your .netcore code had the exact same issue, if you described somewhat “random/sporadic” failures.
If I have time tomorrow I might try to look at the servicestack source, but I’m pretty slammed at the moment, and not really sure how I’ll put together a minimal repro code sample yet
AUTH_PASSWORD isn’t a key in ServiceStack so it’s an issue with the internal ASP.NET APIs, from the StackTrace it appears it’s an internal Exception when accessing the HttpRequestBase.ServerVariables collection for the first time.
One thing you should be avoiding is trying to access HttpRequest object in a background thread, all access should be on the HTTP Request worker thread, i.e. not in a new Thread.
Hmm… ok so it is coming from deeper in .NET. Phooey.
I was unclear, I am not actually spinning up any threads manually/explicitly, threadlock/dirty variable reads was just the best analogy I could think of to describe my guess at the behaviour/possible cause of the issue - ie two processes (in this case two separate requests) trying to initialize the cookie collection for the same user at the same time.
Only thing that still makes me curious/concerned is, what are the odds that my requests could be delivered across two continents, vpn network, and hit the same data collection within microseconds… consistently… and yet fail on apparently randomly accessed cookie keys? That seems highly suspicious, so I will dig through my app logic a bit more.
I will post any updates if I discover any obvious fix, otherwise, for anyone else reading this, you can assume I was left with the hack ‘fire a first request’ work-around.