Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Server cannot append header after HTTP headers have been sent #74

Open
ArtemAvramenko opened this issue Jun 15, 2017 · 61 comments
Open
Milestone

Comments

@ArtemAvramenko
Copy link

ArtemAvramenko commented Jun 15, 2017

Occasionally CookieAuthenticationHandler throws HttpException:

    Exception type: HttpException 
    Exception message: Server cannot append header after HTTP headers have been sent.
   at System.Web.HttpHeaderCollection.SetHeader(String name, String value, Boolean replace)
   at Microsoft.Owin.Host.SystemWeb.CallHeaders.AspNetResponseHeaders.Set(String key, String[] values)
   at Microsoft.Owin.Infrastructure.ChunkingCookieManager.AppendResponseCookie(IOwinContext context, String key, String value, CookieOptions options)
   at Microsoft.Owin.Security.Cookies.CookieAuthenticationHandler.<ApplyResponseGrantAsync>d__f.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Security.Infrastructure.AuthenticationHandler.<ApplyResponseCoreAsync>d__b.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Security.Infrastructure.AuthenticationHandler.<ApplyResponseAsync>d__8.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Security.Infrastructure.AuthenticationHandler.<TeardownAsync>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Security.Infrastructure.AuthenticationMiddleware`1.<Invoke>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContextStage.<RunApp>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContext.<DoFinalWork>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.StageAsyncResult.End(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Version of Microsoft.Owin.Security: 3.0.1

Is this problem fixed in the latest version?

@Tratcher
Copy link
Member

@Tratcher Tratcher added this to the Backlog milestone Jul 13, 2017
@FrediPouce
Copy link

Hi,

We have excactly the same issue.
Anyone could provide a workaround to avoid the issue ?

Two ways to reproduce the problem:

  • Using the OnSendingHeaders method
  • Set the header of the response before doing the redirection or writing the body (here the exception is System.ArgumentException: Value does not fall within the expected range, coming from System.Web.Hosting.IIS7WorkerRequest.SetKnownResponseHeader)

Thanks for your help.

Microsoft.Owin.Security: 3.0.1 and tested also with the version 3.1.0 (same issue)

@dmytro-gokun
Copy link

We also have the same issue with Microsoft.Owin.Security 3.1.0

@chrisjsmith
Copy link

Same issue here.

@xantari
Copy link

xantari commented Jan 4, 2018

Still seeing this with .NET 4.6.2. Some indications that this occurs when the sliding expiration cookie gets renewed.

Possible rleated issue, with OwinServerCompressionHandler: azzlack/Microsoft.AspNet.WebApi.MessageHandlers.Compression#13

@sanjogs
Copy link

sanjogs commented Jan 31, 2018

Same issue here with WebForms. Any chance this is getting addressed in next update?

@Tratcher
Copy link
Member

Tratcher commented Feb 1, 2018

Unfortunately the deprecation of Codeplex has broken all of our links...

The only repro I have for this right now is when you request a root page like "/" and internally it gets routed to a default file like "/default.aspx". IIS uses a feature called child requests to execute "/default.aspx" so it looks like the request is executed twice. The child request "/default.aspx" works fine and the client gets that result. After that duplicate logic runs on the origiinal "/" request. It doesn't know the response already started so CookieAuth tries to refresh it's cookie and throws. The client gets the response from the child request, so the only impact of the failure is an annoying log.

Does this match anyone's experience?

@sanjogs
Copy link

sanjogs commented Feb 2, 2018

@Tratcher I think that's exactly what we are experiencing, the errors we are getting is at the root '/'. Problem is just the annoying log, client does not experience any issues.

@xantari
Copy link

xantari commented Mar 2, 2018

Any news on this one?

@Tratcher
Copy link
Member

Tratcher commented Mar 2, 2018

@xantari does #74 (comment) match your experience?

If this only manifests in a log and does not impact clients then it's a low priority to address.

@xantari
Copy link

xantari commented Mar 2, 2018

@Tratcher We get an email on all errors, receive several hundred of these a day. Also our SIEM (Security Information and Event Management) systems are also receiving those logs since they harvest from the event log and consuming unnecessary space our our SIEMS and causing unnecessary log reviews by our security administrators. Additionally, they are also replicated to our tripwire log server as well, and in the windows event logs. All of which sifting through is causing us pain, when we want to see the real errors in our applications. It is a LOT of noise, that causes us a lot of pain.

@xantari
Copy link

xantari commented Mar 2, 2018

We have spent countless hours so far trying to figure out why it occurs, but have come up empty. We currently have a contract in process to hire an external expert to see if they can fix the issue. Spending thousands on that contract.

@bbarrick
Copy link

bbarrick commented Aug 10, 2018

We are getting this error now after upgrading to 4.0.

@kemmis
Copy link

kemmis commented Aug 16, 2018

would like to see this fixed. lots and lots of noise in our log.

@Workshop2
Copy link

We get loads of these in our logs - are there plans to fix it?

@Tratcher
Copy link
Member

See above. #74 (comment)

@irfan-yusanif
Copy link

When a hit my website's page after about 20 minutes of inactivity, I get this warning in event logs "Server cannot append header after HTTP headers have been sent", and the user is logged out.

I can't see any other reason to logout the user, i think this is expiring the cookies?

@Tratcher
Copy link
Member

Tratcher commented Jan 8, 2019

@Watoo sounds like a sliding refresh of the cookie.

@jeremeguenther
Copy link

Has anyone found a fix for this issue?
I am not aware of any Owin upgrades I have done recently, I am using version 3.1.0.0, which has been running fine for quite awhile. Now all of a sudden my logs are getting filled with this odd HTTP headers error.

It's always thrown at the application level, two identical errors are always thrown one after the other, and it is always at the root of the site, and always by a logged in user.

So it sounds very much like it might be triggered by some sliding cookie issue as mentioned prior in this thread.

This is the stack trace:

Message: Server cannot append header after HTTP headers have been sent.
StackTrace: at System.Web.HttpHeaderCollection.SetHeader(String name, String value, Boolean replace)
at Microsoft.Owin.Host.SystemWeb.CallHeaders.AspNetResponseHeaders.Set(String key, String[] values)
at Microsoft.Owin.Infrastructure.ChunkingCookieManager.AppendResponseCookie(IOwinContext context, String key, String value, CookieOptions options)
at Microsoft.Owin.Security.Cookies.CookieAuthenticationHandler.d__f.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 Microsoft.Owin.Security.Infrastructure.AuthenticationHandler.d__b.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 Microsoft.Owin.Security.Infrastructure.AuthenticationHandler.d__8.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 Microsoft.Owin.Security.Infrastructure.AuthenticationHandler.d__5.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 Microsoft.Owin.Security.Infrastructure.AuthenticationMiddleware`1.d__0.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 Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContextStage.d__5.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 Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContext.d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.StageAsyncResult.End(IAsyncResult ar)
at System.Web.HttpApplication.AsyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)
at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

@Tratcher
Copy link
Member

See #74 (comment)

@jeremeguenther
Copy link

I read the thread already, that is why I posted here. We all know the issue exists, which is what comment 74 confirms. What I asked is if there was a work around to fix it until the code base has been fixed.

Like others here this is filling up my error logs and has wasted a lot man hours reviewing logs for what seems to be a known bug. But it is not a consistent bug for everyone, which means there is probably a work around that could be implemented.

At the moment it sounds like this thread is saying Microsoft views this issue as such a low priority that not only is it not going to fix it any time soon, it isn't going to look into a work around either. I am hoping some other brilliant person has found that work around.

@phaselden
Copy link

phaselden commented Feb 26, 2019

It might not be ideal, but until this is addressed we prevent these getting into our logs we capture and ignore them in the application-level error handler. e.g.:

Exception exc = Server.GetLastError();
if (exc.GetType() == typeof(HttpException) && exc.Message.Contains("Server cannot append header after HTTP headers have been sent"))
{
	Server.ClearError();
}

@jeremeguenther
Copy link

That is similar to the approach I am taking, I am setting a unique flag on this type of error so I can ignore it. It is not a good solution though because that Message could very well be a valid error message for the site if I were to mess up and try and set headers somewhere in code after the response has already been sent.

@rcorfman
Copy link

rcorfman commented May 2, 2019

So is there a way to work with this? Yes I've read #74 comment and that does seem to match my experience. But for my app, this does affect clients as certain claims that were just created are no longer in the identity. The current work around is for users to log off and sign back in, or to just have a coffee and try again later. But that seems to be temporary since this may occur again a short time later. I suppose I could move the claims into application user but that seems counter to the whole claims concept.

@Tratcher
Copy link
Member

Tratcher commented May 2, 2019

@rcorfman in the repro above (#74 (comment)) the client gets the response from /default.aspx, but not the from the duplicate request to /. Are you producing different results on the first and second request? Or do you have a different repro?

@rcorfman
Copy link

rcorfman commented May 2, 2019

@Tratcher thanks for the quick reply. I catch the exception in Global.Application_Error and at that point the raw URL seems to always be "/". Beyond that, I don't know. I haven't been able to reproduce this, I just see the results in my web app's log files. When a user signs in or gets authenticated through a cookie, the app retrieves some user information from a third party web service which is then saved as claims. Those claims are lost when this occurs. I recently converted my webforms app from membership to identity.

@Tratcher
Copy link
Member

Tratcher commented May 2, 2019

When a user signs in or gets authenticated through a cookie, the app retrieves some user information from a third party web service which is then saved as claims.

In this scenario that should be happening twice, and the user should be getting the results from the first one. I'd only expect a user facing problem if the claims were different from the second request.

@rcorfman
Copy link

rcorfman commented May 3, 2019

@Tratcher It only happens once though that's probably because I never moved it out of Global.Session_Start. I glanced at moving it to ApplicationUser.GenerateUserIdentity, but I don't yet understand the flow for when/how it is called.

@jeremeguenther
Copy link

It looks like Owin has two bugs in it:

ChunkingCookieManager.cs method AppendResponseCookie has the error this thread was started for where it tries to modify headers without checking to see if it can first. You can get around this error by creating a custom CookieManager : ICookieManager and wrap the ChunkingCookieManager.

But then you come up against the second bug CookieAuthenticationHandler.cs method ApplyResponseGrantAsync about line 275 sets headers without first checking to see if they were already sent.

I have not yet figured out how to wrap/replace the CookieAuthenticationHandler, but at some point this gets rather silly as we could just end up replacing most of owin depending on how many of these bugs exist.

@Tratcher
Copy link
Member

@jeremeguenther in every case that we've seen this bug, the request is actually a duplicate child request and the response generated (or error) does not surface to the client. That's why the headers are in an unexpected state.

Does anything in your repro indicate otherwise?

@jeremeguenther
Copy link

Yes, I agree with that statement, this is a duplicate request that the client never sees. And according to the IIS documentation this parent/child request is the expected design.

What I am failing to understand is why Microsoft has intentionally designed software that throws generic, uncaught exceptions in standard code. As near as I can tell from my testing this must be affecting all web servers that use owin cookie authentication, it does not seem to be just an "every case" kind of thing; if it were there would be a work around, most people just are not complaining about it. Even catching and throwing a custom exception seems like a better choice.

If this is just an "every case" kind of bug, then I would love to hear what configuration setting triggers it that can be changed to work around it.

So far the response we have gotten seems to be that Microsoft knows this is blowing up web servers, crashing code, filling up logs, and causing additional exception handling overhead on the thread it is running on. But, because it is not visible to the end user, they do not care. I do not understand that attitude, and sure wish I had waited to start using Owin until it was more stable.

@jeremeguenther
Copy link

For those in this thread still looking for a solution. I took @phaselden 's method of handling things and took it a bit further by wrapping the exception to uniquely identify this specific known exception better. I detailed my findings and the work around I ended up going with here.

@Tratcher
Copy link
Member

Tratcher commented Jun 20, 2019

@jeremeguenther nice investigation and writeup. The fundamental issue here is not the exception but the double request execution. If it were possible to detect the duplicate request in a middleware at the start of the pipeline you could short circuit the entire pipeline and the rest of the middleware wouldn't have to worry about it.

In my testing the child request is the more specific one (/default.aspx), it starts second, finishes first, and that's the response the client gets. I don't see a way to detect that a request is a parent of a child, nor any way to preserve state between the two, it doesn't look like anything is shared between them.

@jeremeguenther
Copy link

It looks as though headers get shared. You could set a header and check for its existence/value in the parent code, although I admit that feels like a pretty poor solution as it is more data being sent to the client. But since the middleware itself is generating cookies in this case, maybe there is one of those you could check for.

Here are some additional things that could be tried:

  • ask the IIS team for a feature request allowing this scenario to be detected
  • check if the headers have been written before attempting
  • throw a custom error with custom details, which I believe is standard practice for known things like this if there is no fix.

@Tratcher
Copy link
Member

Clever, I'd tried response headers, server variables, and Items but those aren't shared.

This works fine to prevent the pipeline from running on parent requests.

    public partial class Startup {
        public void Configuration(IAppBuilder app) {
            app.MapWhen(IsChildRequest, ConfigureAuth);
        }

        private bool IsChildRequest(IOwinContext context)
        {
            var childRequestHeader = context.Request.Headers["x-parent-breadcrumb"];
            if (childRequestHeader != null)
            {
                return true;
            }

            context.Request.Headers["x-parent-breadcrumb"] = "1"; // arbitrary value
            return false;
        }
    }

Problem: It works too well. Some requests don't have child requests and we need to allow the pipeline to run for those.

Worst case we could insert a marker like this to prevent ApplyResponseAsync from running twice.
at Microsoft.Owin.Security.Infrastructure.AuthenticationHandler<ApplyResponseAsync>d__8.MoveNext()

protected virtual async Task ApplyResponseCoreAsync()

@jeremeguenther
Copy link

jeremeguenther commented Jun 20, 2019

What if you added an additional constraint on there.
Request.Uri.AbsolutePath == "/"

So far this has only been an issue at root correct? And root requests will always have the parent/child requests unless it is not in integrated mode. A flag, or configuration could be provided to allow developers to specify if they are not running in integrated mode.

Another option, if the request headers are shared rather than copied into the child, would be to do the check later on in the pipeline. Not quite as clean, but then the child request would run first and you would know it existed, and the parent could detect it.

@Tratcher
Copy link
Member

Tratcher commented Jul 1, 2019

What if you added an additional constraint on there. Request.Uri.AbsolutePath == "/"

That's too fragile for framework code. Any call to TransferRequest would trigger the same issue. You're welcome to apply it yourself.

What do you mean by later in the pipeline? At what point would you expect that check to work?

@jeremeguenther
Copy link

The - later in the pipeline - option would only work if the request headers are shared between the two requests. In other words, if the child request modifications can be seen by the parent request. In which case the header could be set in the Configuration method, but the parent would then have to check the request headers at some point after control was returned back to the parent.

That would also require a value to be set somewhere like the response headers that are not shared so the parent could determine if it were the one to set the request header.

Your apply marker idea is probably better than this option, if this option would even work.

@warrenkc
Copy link

Has this been fixed?

@Tratcher
Copy link
Member

@warrenkc no. Do you have any indication it's causing a product issue? All reports so far have only been of log noise.

@warrenkc
Copy link

I really don't know if it causes any issue. But for now I will add this to my Global.asax.cs file:
Exception lastError = Server.GetLastError(); if (lastError.GetType() == typeof(HttpException) && lastError.Message.Contains("Server cannot append header after HTTP headers have been sent")) { Server.ClearError(); return; }

@Tratcher
Copy link
Member

That might cut down on the noise, but it shouldn't have any functional benefits.

@warrenkc
Copy link

warrenkc commented Aug 31, 2020 via email

@Tratcher
Copy link
Member

That's been the case for all reports so far. Let us know if you see otherwise.

@Bykiev
Copy link

Bykiev commented Aug 31, 2020

Is any chance it will be ever fixed? I'm using this library: https://github.com/azzlack/Microsoft.AspNet.WebApi.MessageHandlers.Compression
and because of this bug I need to install additional package OwinServerCompressionHandler to workaround the issue

@dbarrett84
Copy link

dbarrett84 commented Aug 31, 2020

That's been the case for all reports so far. Let us know if you see otherwise.

Hi Tratcher, we are seeing an issue for the end user just recently.

A particular customer has setup their session timeout to be 16 minutes.
We have some API endpoints that could take up to 5 seconds to complete and return a response.

Anytime a user makes a request to one of these API endpoints on the 8 minute mark, they get no response from the server.
From dev tools it will look like a failed request, but the request was successful just the endpoint could not return the response because of this issue.
image

@Tratcher
Copy link
Member

@dbarrett84 that seems to be a different repro than the others reported so far.

This exception should only happen if the AddOnSendingHeaders callback does not fire. So far we've only been able to identify the child request scenario where it fails. Unless this is a webforms app? There have been a few reports about failures there.

How are you generating responses?

@dbarrett84
Copy link

@dbarrett84 that seems to be a different repro than the others reported so far.

This exception should only happen if the AddOnSendingHeaders callback does not fire. So far we've only been able to identify the child request scenario where it fails. Unless this is a webforms app? There have been a few reports about failures there.

How are you generating responses?

@Tratcher thanks your response, we are not registering a callback for AddOnSendingHeaders.
We are within a web forms app though, our app is a hybrid of web forms and web api calls - as we slowly move our monolith into the new world :)
Is there any work-around for the cases where this is occurring in a web forms app??

@Tratcher
Copy link
Member

You can at least wrap the ChunkingCookieManager on CookieAuthenticationOptions.CookieManager to catch and suppress the exception. You could also try the SystemWebChunkingCookieManager to see if it has the same issues.

@dbarrett84
Copy link

The exception is not really our problem, it is the fact the response has already been sent when it shouldn't be.
So the API is unable to respond to the end user, because the http headers have been sent.

I will explore if SystemWebChunkingCookieManager is an option for us.

@MohammadMod
Copy link

any news about this problem has been fixed or not? actually, it took months for me and I face this noisy error.

@dbarrett84
Copy link

dbarrett84 commented Jan 16, 2021 via email

@jwidmer
Copy link

jwidmer commented Jan 18, 2021

We are experiencing this issue too. We are on the latest OWIN packages. Logs show it is on any request where the root path is requested (e.g. /tools, /features) but we have a default.aspx which is handling the page (e.g. /tools/default.aspx, /features/default.aspx).

@kysu1313
Copy link

Hi has there been any update for this issue? We are experiencing this issue however clearing the error doesn't seem to work every time.

@Tratcher
Copy link
Member

Tratcher commented Jul 13, 2021

This issue is not currently under investigation. It was determined that these errors did not impact live requests, they primarily cause log noise. Are you seeing otherwise?

@chrisjsmith
Copy link

600 logs a second in our case. We've filtered them out but this has been open 4 years...

@Tratcher
Copy link
Member

Tratcher commented Jul 15, 2021

Understood. This project is not under active development, development resources have moved to AspNetCore. We've taken a few community contributions, but no viable solution has been found for this specific issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests