0

I have an MVC Web API project that I am working on. I created a controller with an action. I am able to hit the action properly using Postman, but when an external system tries to reach my controller, it gets a 500 error. The owner of the external service cannot give me any details beyond that, they can only retry the request.

Here is one of the log entries of their requests in IIS log

#Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) cs(Referer) sc-status sc-substatus sc-win32-status time-taken
 2017-02-15 20:38:58 192.168.2.34 POST /Route/to/actionName 8002 - 192.168.2.37 Apache-HttpClient/4.5.2+(Java/1.8.0_102) - 500 0 0 146

First I thought may be the action is being hit, so I added an exception handler and added logging.

[Route("actionName")]
[HttpPost]
public IHttpActionResult actionName(MessageModel message)
{
 try
 {
  // code to handle the action
 }
 catch (Exception e)
 {
   // Code to log exception in the log file
 }
}

Tried above and saw nothing in the log, I have run tests for failed requests to make sure the above exception handler logs and it does.

So the next thing I decided to do was to handle application level errors in Global.asax and log exception there.

protected void Application_Error(object sender, EventArgs e)
{
    if (Request.HttpMethod == "POST")
    {
        var request = SomeMethodToReadRequestContentsInString();

        var service = new SomeExceptionLoggingService();

        var exception = Server.GetLastError();
        if (exception == null)
        {
            exception = new ApplicationException("Unknown error occurred");
        }
        service.LogException(exception, Request.UserHostAddress, Request.UserAgent, request);
    }
}

And to my surprise, nothing in the log file.

So then I decided to log ALL Post requests and see if I register ANYTHING in the log.

protected void Application_EndRequest(object sender, EventArgs e)
{
    if (Request.HttpMethod == "POST")
    {
        var request = Helper.ReadStreamUnknownEncoding(Request.InputStream);

        var service = new InterfaceTestingService();

        var exception = Server.GetLastError();
        if (exception == null)
        {
            exception = new ApplicationException("No Error in this request");
        }
        service.LogException(exception, Request.UserHostAddress, Request.UserAgent, request);
    }
}

And again, nothing!

How do I catch this bug? My goal is to see the Content-Type, and contents.

I tried to add a Custom Field in IIS log settings to include `Content-Type', but the log files still don't have that.

enter image description here

fahadash
  • 3,133
  • 1
  • 30
  • 59
  • Turn on debugging on your server then you'll get the actual error and not the generic error page...just make certain that you turn it back off as it's a huge security risk. – BillRuhl Feb 16 '17 at 14:58
  • @BillRuhl The caller cannot offer me more information beyond the HTTP Status code returned (yes it is silly). What's more befuddling is why I am not able to catch it in global asax handlers. – fahadash Feb 16 '17 at 14:59
  • Well, I think they pretty much *have* to give you more info. Understandly, they can only get what your server returns as a response in terms of the actual error that's occurring, but they have more information that can help you troubleshoot, namely: the URI, the request method, and the request body. Given that you're logging only POSTs and you're not getting any logs, my guess would be they aren't even doing a POST. They could also be calling the wrong endpoint or sending the wrong kind of data or data in the wrong format. You need that information. – Chris Pratt Feb 16 '17 at 15:18
  • @ChrisPratt As stated in the IIS Log file (one log line posted in question), their request is indeed a post request, they are hitting the correct endpoint, they have the correct route. – fahadash Feb 16 '17 at 15:24
  • You could try an RDT client like Team Viewer or Ammyy. Remote into the machine their using to make the request. Make the request and observe it in the dev tools of chrome, firefox, or even (cough) ie.... Then you could get the exact request headers they are sending. – BillRuhl Feb 16 '17 at 21:19

1 Answers1

0

I added a handler for Application_BeginRequest logging everything I did in Application_EndRequest. And it turns out, the content-length was zero, and there was no content. I also restarted IIS Web Server to get it to log custom fields too.

What's strange is that if I send empty content through Postman, I get the action code executed but for some reason when they do it, it doesn't.

fahadash
  • 3,133
  • 1
  • 30
  • 59