aspnetcore: Kestrel returns 400 before reaching any of my code

Our web app started returning seemingly random 400s since the last two weeks. It is a ASP.NET Core 2.0 mvc web site running under IIS and Windows Server 2016. First thing we did was, of course, look at our logs. However, there was nothing. None of those 400s were there. We then enabled Failed Request Tracing and found this: https://pastebin.com/NVR2pzbJ (as you may know, Failed Request Traces from IIS are quite gigantic, thus I’m using pastebin). Anyway, the TLDR is this:

<EventData>
  <Data Name="ContextId">{80002F02-0002-EE00-B63F-84710C7967BB}</Data>
  <Data Name="ModuleName">AspNetCoreModule</Data>
  <Data Name="Notification">128</Data>
  <Data Name="HttpStatus">400</Data>ç
  <Data Name="HttpReason">Bad Request</Data>
  <Data Name="HttpSubStatus">0</Data>
  <Data Name="ErrorCode">0</Data>
  <Data Name="ConfigExceptionInfo"></Data>
 </EventData>
 <RenderingInfo Culture="en-US">
  <Opcode>MODULE_SET_RESPONSE_ERROR_STATUS</Opcode>
  <Keywords>
   <Keyword>RequestNotifications</Keyword>
  </Keywords>
  <freb:Description Data="Notification">EXECUTE_REQUEST_HANDLER</freb:Description>
  <freb:Description Data="ErrorCode">The operation completed successfully.
 (0x0)</freb:Description>
 </RenderingInfo>
 <ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
  <EventGuid>{002E91E3-E7AE-44AB-8E07-99230FFA6ADE}</EventGuid>
 </ExtendedTracingInfo>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
 <System>
  <Provider Name="WWW Server" Guid="{3A2A4E84-4C21-4981-AE10-3FDA0D9B0F83}"/>
  <EventID>0</EventID>
  <Version>1</Version>
  <Level>4</Level>
  <Opcode>56</Opcode>
  <Keywords>0x0</Keywords>
  <TimeCreated SystemTime="2018-09-06T13:58:08.103Z"/>
  <Correlation ActivityID="{80002F02-0002-EE00-B63F-84710C7967BB}"/>
  <Execution ProcessID="3828" ThreadID="14428"/>
  <Computer>siip</Computer>
 </System>
 <EventData>
  <Data Name="ContextId">{80002F02-0002-EE00-B63F-84710C7967BB}</Data>
  <Data Name="HeaderName">Content-Length</Data>
  <Data Name="HeaderValue">0</Data>
  <Data Name="Replace">true</Data>
 </EventData>
 <RenderingInfo Culture="en-US">
  <Opcode>GENERAL_SET_RESPONSE_HEADER</Opcode>
 </RenderingInfo>
 <ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
  <EventGuid>{D42CF7EF-DE92-473E-8B6C-621EA663113A}</EventGuid>
 </ExtendedTracingInfo>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
 <System>
  <Provider Name="WWW Server" Guid="{3A2A4E84-4C21-4981-AE10-3FDA0D9B0F83}"/>
  <EventID>0</EventID>
  <Version>1</Version>
  <Level>4</Level>
  <Opcode>56</Opcode>
  <Keywords>0x0</Keywords>
  <TimeCreated SystemTime="2018-09-06T13:58:08.103Z"/>
  <Correlation ActivityID="{80002F02-0002-EE00-B63F-84710C7967BB}"/>
  <Execution ProcessID="3828" ThreadID="14428"/>
  <Computer>siip</Computer>
 </System>
 <EventData>
  <Data Name="ContextId">{80002F02-0002-EE00-B63F-84710C7967BB}</Data>
  <Data Name="HeaderName">Server</Data>
  <Data Name="HeaderValue">Kestrel</Data>
  <Data Name="Replace">true</Data>
 </EventData>
 <RenderingInfo Culture="en-US">
  <Opcode>GENERAL_SET_RESPONSE_HEADER</Opcode>
 </RenderingInfo>
 <ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
  <EventGuid>{D42CF7EF-DE92-473E-8B6C-621EA663113A}</EventGuid>
 </ExtendedTracingInfo>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
 <System>
  <Provider Name="WWW Server" Guid="{3A2A4E84-4C21-4981-AE10-3FDA0D9B0F83}"/>
  <EventID>0</EventID>
  <Version>1</Version>
  <Level>5</Level>
  <Opcode>3</Opcode>
  <Keywords>0x100</Keywords>
  <TimeCreated SystemTime="2018-09-06T13:58:08.103Z"/>
  <Correlation ActivityID="{80002F02-0002-EE00-B63F-84710C7967BB}"/>
  <Execution ProcessID="3828" ThreadID="14428"/>
  <Computer>siip</Computer>
 </System>
 <EventData>
  <Data Name="ContextId">{80002F02-0002-EE00-B63F-84710C7967BB}</Data>
  <Data Name="ModuleName">AspNetCoreModule</Data>
  <Data Name="Notification">128</Data>
  <Data Name="fIsPostNotificationEvent">false</Data>
  <Data Name="CompletionBytes">0</Data>
  <Data Name="ErrorCode">0</Data>
 </EventData>
 <RenderingInfo Culture="en-US">
  <Opcode>NOTIFY_MODULE_COMPLETION</Opcode>
  <Keywords>
   <Keyword>RequestNotifications</Keyword>
  </Keywords>
  <freb:Description Data="Notification">EXECUTE_REQUEST_HANDLER</freb:Description>
  <freb:Description Data="ErrorCode">The operation completed successfully.
 (0x0)</freb:Description>
 </RenderingInfo>
 <ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
  <EventGuid>{002E91E3-E7AE-44AB-8E07-99230FFA6ADE}</EventGuid>
 </ExtendedTracingInfo>
</Event>

Now, I’m not an IIS expert by any means, but if I understand this correctly, Asp.Net Core has run and has decided to return 400 bad request. The problem is: our code never ran. This is our Startup.Configure():

public void Configure(IApplicationBuilder app, IHostingEnvironment env)
        {
            // This middleware, as you can see, is the first thing ever to run and it simply logs
           // everything that enters and leaves. Do note that other "normal" 400 errors are logged by this
            app.UseMiddleware<SerilogMiddleware>();

            if (env.IsDevelopment())
            {
                app.UseDeveloperExceptionPage();
                app.UseBrowserLink();
            }
            else
            {
                app.UseExceptionHandler("/Home/Error/500");
            }

            // other middleware ...

            // This turns 400s, 404s and 500s into some pretty pages.
            // And this middleware is also not being run when this problem occurs,
            // further evidencing that Kestrel is returning 400 _before_ any of my code runs.
            app.UseStatusCodePagesWithReExecute("/Home/Error/{0}");

            app.UseMvc(routes =>
            {
                routes
                .MapRoute(
                    name: "default",
                    template: "{controller=Home}/{action=Index}/{id?}");
            });
        }

We thought that maybe the request got corrupted and somehow it was so invalid that kestrel didn’t even bother to send it to the rest of the pipeline. However, we’ve repated the same request on fiddler and they return success codes. This is the request if you don’t want to navigate through those 4k lines of log:

Cache-Control: max-age=0
Connection: keep-alive
Content-Length: 2410
Content-Type: application/x-www-form-urlencoded
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: pt-BR,pt;q=0.9,en-US;q=0.8,en;q=0.7
Cookie: .AspNetCore.Antiforgery.yRvNsY19ltY=CfDJ8DgfkYSRB59EqqhuWGHNsd9RwNppJLY8SuEzNMhyyszJv8tPzAJPfuZ4uwMX8RPtO28x3qVO1FtSXHGrb4pjZLkETcbVr4zDiH4VEuoFYbNqBe6hUKHZrN4Vg_5LIGCfY6vVLtnX1Dl7QCy3arKjRVY; .AspNetCore.Cookies=CfDJ8DgfkYSRB59EqqhuWGHNsd_qCE-_zqZcbhiSe47BlGFvLNyIFQ2CyUTMFARZScdH8o0E-LhqGzGgbMPnn5G9-T0KpL7sV0K4uQ1yYA59vo25d42-rtr8WMz2jgEVlYCwiUoZwy0AHBhJstwdilM3_D3FxkJTzebye8BHOrjobdeOqTWk4D774_V4M-O2-pltX3On_U0vKheQGc2-YrGwP4RFlR0x9XSrszgtKyRv_mJE67g9ueRD1aRRp9-BGoymJujrxjDnuPD7ZIN1RWlstiV5RyQpsjnurMISgNsl6ET5wRH0-Bu2p-RNnjAiFHAlCjom4RKb7pKDXMipaQoEGkwesn4T02kV5R4NhwrUOzbyUFZ1aWltOFuDp6Ce3pMAnPNtx2SsUN0ru7T3Yjc1pUIEZW3_quxcHQnrb601NGRHZpmoIqVOJSIFOhuX-rgYhGWfBUHtqckv2Cb-WiS1sIrR0Za7E692mQkVvbN5uT1n1fFbhNLRmixT0empfGtI8ZrKbHDjmVhdOuTvgNRZ3Z0uQx05pjmtITHenYkqCtPja0j-sCqEIhMsfXc2XFj4dNNvTMWEBGHXzTpvqD2CUgpBt2fHxC2fm8tRXZPWgojqVrM4JRMS03sl5nf92RIbtubVc8gsRNYIZPftLdl193PmosGSAYhpiU6XyRwh7d4KILEgsXJPZXiwY5UTmBCqW84aHRv9X9ZZ1P-e9jvBHm_31gR8IbiFeiZqGTRF8_cPDYuBd43fuA0z_L1G8LpcNaQrbDm-CrVuaWLpr8aQy-VzrQJMiCJWUxo9sQRZGCaK_Jl_ukRKn-YHelY9nNAAcWitiPLdqQYal194oLYPYo4t7K9ftGQuib4NJa7I8TwXeKK1Qy6TVupTQgUNIjO_yvRiZyrnvq5oaOP9V9SYT4_nppOhryaqVQ-jJRY4XKxqnP5shwDbPtOVFg-67ozWebX_a7EHSzULIvSoBUsR7utlhZCmmBJGgBZZhJfr2-6GWwcdcJ23Sz0x5JyW-O4Liw4ErXnbEdSvZTomjS2pjqleG_TsBJS6xCEIStSRRiyxZduG9ihmQB1fCGC8DhTmckU0-M_quPsHGjBahr7f1MNx6yXxF5ms4CHSvG-i7Lhh-WDDRLg21dBvtFrvT65bYsoRPHsukfi-6dT3oS49KdriqCNKTa5o4nWX98563be0znJTj8T_1eXOrYcjRfYThZnkB8OpJjz1Eihaj7bgQ-N6zuK3NWJSU3j4EA2s15qgrnVzCEXcd37HpQxRzTtCJ0eS-EY062xf3RW441WRY1-bhqjsAgajW6JCgkh7Ukb4W-_accuiUjW0U2jSepyUysdTva64JwF8hKF7ap1StomK1U7Dxg10hLJ3vMfqW1G5Tbo-ahQCVhBxhgKjsCFUFALdQUlWgnfsXMyr-6wbT273lQ7xsYW2HzhkSLYyWbkZLXEP5QJjm4hgb8EEEJYrLLkwqAyu5uO7CLqbLbKlytAH5rAcvnWq6J2yZfC_diNoRW35gaw96RV51OTI2CQTOPzYzqZTfUYmkhuNeGkNIZqgPOKJivZu5aSNMBBrzqXPcDAPmHEOKTlNODtiN1f3sE1XzPUz2CWRf-GMTO6NwdrRYgx2Y6aTf_XCElC5z6Rk1dK04yhR9xBKq_l35YjyuZNPg9ArO46jhfBM1WbaB_tmBPob9dSEuW5kXNnfBZ-CbWJZEioequiVC-_Z2PGtbOeRkFtCfPgk07t9kVskNjYHtFRSmEB7kmC-DYDFz29SXicjsgTko05tmviT_XxTDaAtdQfoYap5QF8BTgSW9L2uvDPB3XS5QUhiKSbXtU-UUoQp4uJ_zGwg3H-2bsTiieG2ZfGZ7uRKGQ1we-WWp1Jb-4ADv28ZQrQuYaNfRtelIxixDmUWoOoygIvGV_K-Ini27CPeZ8ys5oG3LiW-sQND_eVIluCGwY3RkorPhgmggAKOsHIvqRyzD3Y0PtdUkqN2J5cODm4sADZl9J_0uFhe4q-dnCyeqQhDbKfIr3nCiHehKfsBKKa_49aOF0ZhH9z5quZvymtWo3mAJp3VUNTdJcAqYnvWWydS3gLhlGz2AJxkpnzVd0XDaTy4y3yDoS_h15efbjZjI6hrByCAg48phLByXJ0aJYKeh-7Qf-lsvVpixkQKOWie5weN8LWKbE5z8HdKVW0gL_2me7fh1k8PdI3wyX6dvG1K6Ez0GN2nWl0wNUQknyj9xCAr2IOzmNXXJkDHzLBxtvIJvUqRQTN5MRwmz-Mp-CUjdiexokVSa8s87Dts-YLkY9d9dy2SWSPuhfowr9XnBjuRBkv62kQMAFQzvxMiz0vdj-cLRTclH8xWYg4damLkJ_ugUXMUPEixKPMurLOlYL9GxlFaiIjvytj9g2Y53C2LrQWtrJakNuweHXSQsSSUiUl99mDBQzYC2Wg3QmGILCz7_bT4XH_FLYcMQt7QVTASmS_4ikFjIVe4QhWOMWXUFnY9TCYmUkqSYXPtDyd23rbnRU8xZosTH7FLWXH0PnbIs2AsfTmPq52WtIR2tLn1hcgsOR7YqXn_MWE7HLLh_FQdt-x6jSNKpxkFMeR3ZsQXHQzoRqdeb3S17Fe7XD58HhpSPBXcyDgqZK3uu84CLsR-CjY9h3xnKSTSepU9Nqa_KdGIa8Q9bpKAVpu2arnlW6Fxdh7_j9_cPpFS6Jk6mGMH0xh5JE_ZxhICXMlWYCIblD_YBV3HTE7FDGj1gbg-TT6inBnq8PbDXXEOfPa3K1OuqdDgHXvFLwqq0y1PXg3r0c2eYcMIUdS0DBjiIsu6sLqNwPJvdwI-B_aucHCha6ZHNUrSEbLJVqw3HWlZ-CgSSLa_G8JYjzp2k4Lw2HaZd2cYP2H25ZIfDac-mBtgutJN9pIzxvF-qrPatjXjRA8LyPj2H92cy2mKu7WXpvrvvs7JppiSNPVKJFzvR0RmMbvvONUnyQlnrXizwPgwKSOEFLzyl9kvsafzTXVdhUhb3Mo3WYFEng; .AspNetCore.Session=CfDJ8DgfkYSRB59EqqhuWGHNsd8Rf5SAzNzUXxufiopkJheFoufaoaYs2XFLN%2FpaOO9pUyxt3J9noimn8wgCl3vxbuAPNJ0tsqR%2FBiEn0YU2SOFLrPVhGgZ6kd0rn3tmhPHyrZTSVGP%2Ftvow8CPdWg8USxbMhwtKrcwaKq56tmhqcjUm
Host: [redacted-url]
Referer: http://[redacted-url]/Inspecao/Cadastrar
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Origin: http://[redacted-url]
Upgrade-Insecure-Requests: 1

DataAlteracao=&DataInclusao=&Municipio=São+Vicente&Data=13/08/2018&Hora=09:31&

There were other parameters in the body, but I’ve removed them for brevity. You can find all of them on the provided log. Also, note that in the log, the body was url-encoded. We tested both replaying them url-encoded and decoded, both result in our code being run, which is what is really important here.

Edit Some more info: We have this same application deployed to two different physical servers. Only one of them is having these issues, however. These are the differences I managed to gather between the two (italic being the one presenting these issues):

Windows Server 2016 vs Windows Server 2008 Azure VM vs Physical Server Multiple (20+) IIS Websites, all runing ASP.NET Core 2 and 3 running WebForms under .NET 4.5 vs 2 IIS Websites running ASP.NET Core 2 16 GB RAM vs 8GB