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

LoggerPro Queue Full #481

Closed
fastbike opened this issue Feb 12, 2021 · 5 comments
Closed

LoggerPro Queue Full #481

fastbike opened this issue Feb 12, 2021 · 5 comments
Assignees
Labels
accepted Issue has been accepted and inserted in a future milestone as-designed The behaviour is correct/expected open Some team member is working on this

Comments

@fastbike
Copy link
Contributor

We have a DMVC application deployed as an ISAPI 64bit DLL, running under IIS 8 on Windows Server 2012R2. This has been running fine for over 12 months.
Recently as the number of requests has increased we are getting clients reporting 500 errors, with the text of the error "Main logs queue is full. Hints: Are there appenders? Are these appenders fast enough considering the log item production?"
We can trace this to the TLogWriter.Log method which will raise this error if it cannot enqueue the log entry.

To reproduce we have created a very simple DMVC ISAPI app, which has a single controller with a single method. This reproduction app has a loop that creates log entries, and also runs a loop that results in an integer overflow which is logged as an error.

We have also created a JMeter test script which creates a pool of threads and makes calls to the web server. We're finding that we can reproduce the error with it typically occurring with 900 requests being made in short succession to the web server.

The source code for the ISAPI app and the JMeter script are attached. The JMeter will need to be reconfigured to point to the server you end up deploying the ISAPI to. ( it is in the node labelled "HTTP Request Defaults (configure server address here)").

Looking fwd to seeing what is happening in the logger code.
LoggerProReplication.zip

@danieleteti danieleteti self-assigned this Feb 16, 2021
@danieleteti danieleteti added the open Some team member is working on this label Feb 16, 2021
@danieleteti danieleteti added this to the 3.2.2-nitrogen milestone Feb 16, 2021
@danieleteti
Copy link
Owner

Thank you for your sample. Here's some notes about it.

  • The code in TestController.MVCControllerAfterCreate; should not be there. It slows down every request to do I/O. Find a different place in the code to configure your stuff or just save that information in a shared cache (dmvcframework provides different kind of caches, but for just 3 variables you can use a simple "Settings" object factory
  • I reproduced the error even with a console application, so the problem is not IIS. However, LoggerPro works correctly... the action code logs lot of lines, so the queue gets full quickly. In these cases you have 3 solutions:
    1. Dequeue faster
    2. Slow down the appender
    3. Use a larger queue

The simplest thing to do is the 3rd option. However, I changed the custom threadsafe queue to use a cubic wait function instead of the linear one used in the current released version. Please, give it a try. Substitute the unit attached in the folder libs/loggerpro and let me know if it works. Moreover, you can also try to make the queue bigger. However, using this updated unit I cannot reproduce the error anymore. Just let me know.

ThreadSafeQueueU.zip

@danieleteti danieleteti added accepted Issue has been accepted and inserted in a future milestone as-designed The behaviour is correct/expected labels Feb 16, 2021
@danieleteti
Copy link
Owner

Any news? Does the change solve the problem?

@fastbike
Copy link
Contributor Author

Thanks Daniele

We are running some performance tests to check but early results show a fix. We will conclude these on Monday and post another reply.

Thanks for the rapid response.

David

@fastbike
Copy link
Contributor Author

We have completed some performance testing and will be releasing a new version of our HL7 FHIR server tomorrow morning (NZ time).
I'll close this ticket once the release has been completed.

@danieleteti
Copy link
Owner

Great! The change will be integrated in LoggerPro too.

danieleteti added a commit to danieleteti/loggerpro that referenced this issue Feb 25, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
accepted Issue has been accepted and inserted in a future milestone as-designed The behaviour is correct/expected open Some team member is working on this
Projects
None yet
Development

No branches or pull requests

2 participants