Stop attaching a stack trace to every cleanup SQL statement - #1988
Merged
Conversation
DbDriver.StackTraceGenerationException is an empty marker exception, constructed on purpose and handed to the logger so log4j prints a call stack next to the message. In DBBackupAndClean.executeUpdate that stack is invariant -- the method is only ever reached from the cleanup thread through this one path -- so it identified nothing the message and logger name did not. It is not free. cbit.vcell.modeldb is set to debug on the db container (docker/build/vcell-db.log4j.xml:25), so every statement the database cleanup runs was logged with a full synthetic stack trace: about 948 lines a day on production, roughly a quarter of that container's 3823. The message is unchanged, so the SQL visibility the debug level was presumably enabled for is kept. Switched to a parameterized call, which also lets the isDebugEnabled() guard go -- log4j2 does not build the string unless the level is on. Verified by logging both forms side by side through a debug configuration: same DEBUG line, same SQL, no StackTraceGenerationException underneath it. Deliberately narrow. The idiom appears 56 times in vcell-server: 20 at lg.error, 19 at lg.trace, 16 at lg.debug. The lg.error ones are worth keeping -- they fire on genuinely unexpected conditions such as changed != 1 after an update (DbDriver:3585), where the call stack is the only thing that says which of many call paths produced it. The trace ones cost nothing while nothing enables trace. Only this one is generating volume in a deployed configuration. Closes #1987 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closes #1987.
DbDriver.StackTraceGenerationExceptionis an empty marker exception, constructed on purpose and handed to the logger so log4j prints a call stack next to the message. InDBBackupAndClean.executeUpdatethat stack is invariant — the method is only ever reached from the cleanup thread through this one path — so it identified nothing the message and logger name did not.It is not free.
cbit.vcell.modeldbis atdebugon the db container (docker/build/vcell-db.log4j.xml:25), so every statement the cleanup runs was logged with a full synthetic stack trace: ~948 lines/day on production, roughly a quarter of that container's 3823.Before / after
Both forms logged side by side through a debug configuration:
Same DEBUG line, same SQL, no stack trace. The visibility the
debuglevel was presumably enabled for is kept.Switched to a parameterized call, which also lets the
isDebugEnabled()guard go — log4j2 does not build the string unless the level is on.Deliberately narrow
The idiom appears 56 times in
vcell-server, and they should not all be treated alike:lg.errorchanged != 1after an update (DbDriver:3585), where the stack is the only thing identifying which of many call paths produced itlg.tracelg.debugOne line changed, in the one place that is actually noisy.
🤖 Generated with Claude Code