Question Why not errors written to DB?

[raysefo]

Hello,

I have unhandled exception logger which logs every error into a table. Actually, it works but there is a rare condition when I do a load test with more than 1000 users, errors aren't written into this table. (950 success, 50 errors) Why could this happen? Any ideas? 50 users didn't even start for some reason?

public class UnhandledExceptionLogger : ExceptionLogger
    {
        public override void Log(ExceptionLoggerContext context)
        {
            var ex = context.Exception;

            string strLogText = "";
            strLogText += Environment.NewLine + "Source ---\n{0}" + ex.Source;
            strLogText += Environment.NewLine + "StackTrace ---\n{0}" + ex.StackTrace;
            strLogText += Environment.NewLine + "TargetSite ---\n{0}" + ex.TargetSite;

            if (ex.InnerException != null)
            {
                strLogText += Environment.NewLine + "Inner Exception is {0}" + ex.InnerException;//error prone
            }
            if (ex.Message != null)
            {
                strLogText += Environment.NewLine + "Message ---\n{0}" + ex.Message;//error prone
            }

            var requestedURi = (string)context.Request.RequestUri.AbsoluteUri;
            var requestMethod = context.Request.Method.ToString();
            var timeUtc = DateTime.Now;

            SqlErrorLogging sqlErrorLogging = new SqlErrorLogging();
            ApiError apiError = new ApiError()
            {
                Message = strLogText,
                RequestUri = requestedURi,
                RequestMethod = requestMethod,
                TimeUtc = DateTime.Now
            };
            sqlErrorLogging.InsertErrorLog(apiError);
        }
    }

public void InsertErrorLog(ApiError apiError)
        {
            using (var sqlConnection =
                new SqlConnection(ConfigurationManager.ConnectionStrings["GameContext"].ConnectionString))
            {
                try
                {
                    sqlConnection.Open();
                    using (SqlCommand cmd =
                        new SqlCommand(
                            "INSERT INTO [dbo].[API_Error] ([Message],[RequestMethod],[RequestUri],[TimeUtc]) VALUES (@Message, @RequestMethod, @RequestUri, @TimeUtc)",
                            sqlConnection))
                    {
                        cmd.Parameters.AddWithValue("@TimeUtc", apiError.TimeUtc);
                        cmd.Parameters.AddWithValue("@RequestUri", apiError.RequestUri);
                        cmd.Parameters.AddWithValue("@Message", apiError.Message);
                        cmd.Parameters.AddWithValue("@RequestMethod", apiError.RequestMethod);

                        cmd.ExecuteNonQuery();
                    }
                }
                catch (Exception e)
                {
                    throw e;
                }
                finally
                {
                    sqlConnection.Close();
                }
            }
        }

 

[raysefo]

Thank you @Skydiver. If we go back to Connection_Dropped_List_Full issue, so it seems JMeter has dropped the connections. How can I make load test lets say with 2000 users?

 

[Skydiver]

I don't know, but that response that Nan Yu gave you on Forums.ASP.NET looked very good in terms of where to start looking.

 

[raysefo]

That code there looks like it cleanly releases connections.

But this method is async. Should it be async all the way right?

namespace Game.Handlers
{
    public class RequestResponseHandler : DelegatingHandler
    {
        protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request,
            CancellationToken cancellationToken)
        {
            var requestedMethod = request.Method;
            var userHostAddress = HttpContext.Current != null ? HttpContext.Current.Request.UserHostAddress : "0.0.0.0";
            var useragent = request.Headers.UserAgent.ToString();
            var requestMessage = await request.Content.ReadAsByteArrayAsync();
            var uriAccessed = request.RequestUri.AbsoluteUri;

            var responseHeadersString = new StringBuilder();
            foreach (var header in request.Headers)
            {
                responseHeadersString.Append($"{header.Key}: {String.Join(", ", header.Value)}{Environment.NewLine}");
            }

            var messageLoggingHandler = new MessageLogging();

            var requestLog = new ApiLog()
            {
                Headers = responseHeadersString.ToString(),
                AbsoluteUri = uriAccessed,
                Host = userHostAddress,
                RequestBody = Encoding.UTF8.GetString(requestMessage),
                UserHostAddress = userHostAddress,
                Useragent = useragent,
                RequestedMethod = requestedMethod.ToString(),
                StatusCode = string.Empty
            };

            messageLoggingHandler.IncomingMessageAsync(requestLog);

            var response = await base.SendAsync(request, cancellationToken);

            byte[] responseMessage = new byte[] { 0x1 };
            if (response.IsSuccessStatusCode)
            {
                if (response.Content != null)
                {
                    responseMessage = await response.Content.ReadAsByteArrayAsync();
                }
            }
            else
                responseMessage = Encoding.UTF8.GetBytes(response.ReasonPhrase);

            var responseLog = new ApiLog()
            {
                Headers = responseHeadersString.ToString(),
                AbsoluteUri = uriAccessed,
                Host = userHostAddress,
                RequestBody = Encoding.UTF8.GetString(responseMessage),
                UserHostAddress = userHostAddress,
                Useragent = useragent,
                RequestedMethod = requestedMethod.ToString(),
                StatusCode = response.StatusCode.ToString()
            };

            messageLoggingHandler.OutgoingMessageAsync(responseLog);
            return response;
        }
    }
}

 

[Skydiver]

What does code in post #18 got to do with the code from post #14 on which you asked for comments regarding SQL connections got to do with each other? I'm not seeing any calling to ApiLogging.InsertLog() anywhere in post #18.

Furthermore, using async/await in of themselves do no create threads. Please read There is No Thread

Should it be async all the way right?

I assume you are asking this because you saw best practice #2 from here: Async/Await - Best Practices in Asynchronous Programming
I'll quote from Stephen Cleary:

The best solution to this problem is to allow async code to grow naturally through the codebase. If you follow this solution, you’ll see async code expand to its entry point, usually an event handler or controller action.

 

[NoUserHere]

Ah yes, I remember that article being helpful to me a few years ago when I was looking into something similar. Stephen Cleary, certainly a man with a wealth of knowledge.

OP : I have a question nobody has asked you yet.

• How have you ended up with a project where you appear to no so little about the internals and the code you are reporting problems with?
• Surely if you wrote it, you should know what it's doing. Did you write it?
• And surely if you didn't write it, and if you've taken this project on from another developer, you would also be able to understand the concepts of what is taking place in the code you're allowing to execute?

Which you don't. I think it would be more helpful for anyone here to help you, if we understood how much you actually know. And trying not to sound condescending or superior here, but I've been around coding forums for a long time, and I can nearly always tell when someone is probing for answers in something they have very little understanding of. For the sake of my own sanity, I study user replies before feeding them a complex answer or giving them code which they won't know how to interpret; which always results in us teaching you every inch of how yours and our code works. Which really is not our job. It's up to you to educate yourself, as we can only spur you on so far.

I don't think its helpful if you get spoon fed answers on topics where your inexperience is showing through on the basic principles of thread flow. And if you recall going back a topic or two, you were asking me about threading as you wanted to introduce multi-threading as a solution to your connection pool problem which is not going to solve anything in that regard. And while (sometimes) it is rather useful to execute long running processes on another thread, but that is not always required especially if you're not waiting on a result, or if the process is not hindering performance. Instead, you should be focusing on the fundamentals which applies to the code you're using, and then focus on what is eating up your connection pool, and close the holes you've left open.

Sorry, this is off the topic but I wonder does this quickly eat connection pool? Should I change it to a Task (rather than void) and added an await ?

What would you gain from changing to task, and how would you run this task? Does the API class behind execute for a long time? We don't know. Only you know how often these methods are called.

 public void IncomingMessageAsync(ApiLog apiLog)
        {
            apiLog.RequestType = "Request";
            var sqlErrorLogging = new ApiLogging();
            sqlErrorLogging.InsertLog(apiLog);
        }

        public void OutgoingMessageAsync(ApiLog apiLog)
        {
            apiLog.RequestType = "Response";
            var sqlErrorLogging = new ApiLogging();
            sqlErrorLogging.InsertLog(apiLog);
        }

I find it amusing, almost funny that you're experiencing connection pool issues and yet you are trying to log your errors to the database?

 

[raysefo]

@Skydiver and @Sheepings thank you for your feedback. You are right, as I said many times I am not experienced with rest API. I googled a lot and trying to follow step by step tutorials. There was this all in one article (rest API) and mostly referred to this one.

 

[Skydiver]

Here's my suggestion: Create a version of your project where your Controllers essentially just return success without actually do any work. Run JMeter to see if you can get past the 1000 user limit. If you can, then you know that it's the rest of your code that is causing the issue. If it doesn't, then just like the link provided to you by Nang Yu suggests: there is an issue with the load balancer thinking that your application can't handle that number of connections.

 

[raysefo]

Here's my suggestion: Create a version of your project where your Controllers essentially just return success without actually do any work.

@Skydiver thank you, you mean controller just returns 200 right? No handlers, no repositories, no unit of work etc.

 

[Skydiver]

Yes. Figure out whether it is your infrastructure that is causing the problem, or if it is your code.

Chances are that it's your code because as I've said, my web services easily supports that number of users/transactions, but then, I also know how my F5 load balancer and my IIS machines are configured in my environment. It looks like you don't know how your environment is configured.

 

[NoUserHere]

Yea, I think I suggested the same as Skydiver at some point before. Strip out everything, and leave only the guts. Then once you know it works, you will know what to change when putting it all back together again.

You are right, as I said many times I am not experienced with rest API. I googled a lot and trying to follow step by step tutorials.

May I suggest reading this : Asynchronous programming in C# It is an excellent piece with really easy to follow analogies on how and when to use await and it is very informative re- asynchronous programming. Grab a cup of tea and dig in. It's only a ten minute read.

 

[raysefo]

but then, I also know how my F5 load balancer and my IIS machines are configured in my environment. It looks like you don't know how your environment is configured.

My server is in the cloud. I asked the admin if the server is behind the LB or any other configuration issues.

 

[Skydiver]

Something to keep in mind: Most cloud based hosting worth their salt have automatic DOS (and DDOS) attack detection and prevention. If the system sees a pattern or burst of multiple connection attempts, it will automatically throttle the incoming connections by stopping or denying the other connection attempts. (Yes, from one point of view, this can be seen as the DOS attack has been successful because some people were denied service, but it does keep the system running.) If your JMeter test is only emanating requests from a single IP, then it looks even more suspiciously like a naive DOS attack.

In a way, a load test is a DOS attack if the purpose of the load test is to find the breaking point, as opposed to a load test meant to discover how the system performs when under that expected/designed for load.

A side question is: Is that your webservice even supposed to handle that many users in a such a small amount of time? Is it in the acceptance criteria for your web service, or just something that some one arbitrarily picked? If it is in the acceptance criteria, presumably someone had a logical reason for picking that number that is based in reality, rather than just for bragging rights. For example, on one system we have, we planned to support 90,000 users logged on and running simultaneously, but realistically not all 90,000 will all hit the logon page all at 8:00 AM Eastern. The users were actually spreadout across multiple timezones, and based on our research of AD logon logs, people within each timezone tended to be spreadout over a 3 hour period from 7-10AM. So our load testing simulated this type of behavior, instead of the originally conceived idea of 90,0000 people all logging in over a 15 minute period.

 

[raysefo]

@Skydiver thank you. Hopefully, it is due to attack detection and prevention of the host

If your JMeter test is only emanating requests from a single IP, then it looks even more suspiciously like a naive DOS attack.

Yes, I am testing from a single IP, which is my development laptop.

Is that your webservice even supposed to handle that many users in a such a small amount of time? Is it in the acceptance criteria for your web service, or just something that some one arbitrarily picked?

It is my web service but it does not have to handle such a small amount of time. (Not an acceptance criteria) Actually, I think concurrent 350 users are more than enough but who knows there may be more than that in future. So I need to know if I can handle more users.

 

[NoUserHere]

I highly doubt that, and I say that because I work with this stuff almost daily. Worth a note @Skydiver; OP is creating connections but the connection in the pool are not being released; hence becoming full. So connections are entering the system. You have made a good point re what could be seen as a denial of service by lambasting the server with connections form the same IP. But this would not cause CloudFlare to hold any resources from sending packets back to the application or stopping it from closing a connection. Note, in between connections, a connection to the server was refused error would likely occur. If this was a CloudFlare issue, OP would not be able to access his network at all and would likely need it to be unblocked VIA an administration request. @raysefo, I suggest that you contact your network administration and ensure that they white-list your IP which you are testing from. This is something you should have known to do from the get-go. But its obviously not the cause of your issue in my opinion. That's not to say that the problem may not be something else server-side. Knowing more about your configuration might be helpful to narrowing causes, but I'd firstly do as said on post #22 before anything else.

 

[Skydiver]

It looks like the OP is having two different kinds of connection issues: There's the database connection issue where he is exhausting his database connection pool. Definitely suspicious there.
Then there's his IIS connection issue (e.g "Connection_Dropped_List_Full"), where IIS has stopped sending requests to his application. Although the primary reason why IIS won't send anymore connections to his app is because it is busy (likely because of some bug that is also causing the database connection exhaustion) the link that Nan Yu provided in the OP's ASP.NET Forums thread (see post #17) also suggests another potential reason for the connection dropped error: some load balancers will allow the initial connection and then shut it down before IIS can get around to servicing it because the load balancer thinks that IIS is unhealthy or busy.

My gut feel though is that it's very likely the OP's code, but it's worth confirming that the infrastructure + MVC is working correctly first, so that the OP can focus on just the code, instead of trying to figure out if it's the environment or if it's the code.