Cheers for coming back to me @Zackster . I can answer most of these.
One of your team asked on slack about updating settings on every single request, and that’s mentioned above, are you still doing this?
We’ve given you a bum steer here. It’s done once at application start. This is a work around for the Lucee bug introduced between 5.3.9.133 and 5.3.9.166 (I think) wherein writeLog(file="x", level="y", ...)
stopped working for any level below ERROR because Lucee was resetting the default log level to ERROR under the hood. This was your recommended way of addressing this.
NB: one idiosyncratic point in our code here is we’re using file="fileName"
, not log="logName"
. However this has always been the case.
Do the lucee-server.xml or lucee-web.xml still reflect your desired settings once the problem starts?
I can’t answer that as I did not check at the time (and like I said, the containers have been rolled back now). But I did check the UI in Lucee admin and that was reflecting the correct settings, yes.
Using the admin API for logging, do the returned values also match your expectations?
I cannot test this. We have rolled the containers back, as I said. I cannot try anything new here.
Define the logs in the admin and reference them via log, which then uses the shared, configured pooled log file adapters.
We’re dealing with containers mate. Cattle vs pets. There is no “configuring stuff via the admin”. That is an archaic notion.
Circling back to docker, is this a case of works on my machine but fails in prod / with load?
I’ll repeat what I said in from the post you are replying to:
Another consideration here. We have three identical containers; the issue only occurred on one of them. It’s not the heaviest traffic one, but it’s the one that is doing the most logging, given the nature of its usage. And it happened reproduceably on that.
I could not replicate in our dev environment either.
None of this is very high traffic: for all intents and purposes it’s an internal application, not a public-facing web application.
We have one container that that is servicing humans using the UI… basically a CRUD interface to a DB. Looking at y/day’s traffic, it’s peaking @ 4req/sec. It largely only logs things when something goes wrong (intrinsically at a higher level than INFO), but still logs a bit of telemetry @ INFO level too This container had no problems.
The other container basically does batch processing via scheduled tasks. This does a lot of heavy data processing (and logging), but only runs one request (task) at a time. It logs a lot of telemetry @ INFO level, and some stuff at a higher level than that. This is the container that was bung.
It is not a case that some log files reset their log level to ERROR; it happens to all of them at once. One moment; we’re getting INFO log entries constantly; next moment it stops. It seemed to be maybe 5min after the container & application started, but as it was a mission critical server I had to sort it out immediately. Log entries at ERROR continued to log.
Restarting the app (so hitting the log config code in onApplicationStart
) did not fix it. Restarting the container did. For a while.
It doesn’t seem to be to do with updateLogSettings
. But on the other hand re-running that also doesn’t actually help.
In your position, I would be looking at any code you have that monkeys with logging settings that is not triggered by human user interaction (so like as the response to updates to the Lucee admin UI, or active calls to updateLogSettings
, etc), and ask “why are we running this code? What runs this code?”. If you have code that is “trying to be a big help” or second-guessing what might be going on and “fixing” stuff, or addressing this issue automagically instead of throwing an error… I’d question its validity. Just a guess though.
Hope this lot helps. Sorry I’m not in the position to run any testing; but business continuity is more important than upgrading Lucee or troubleshooting logging issues whilst we lose critical log information. I can’t roll Lucee forward again to test stuff.
Cheers pal.