A common problem in Java is someone will drop a log that looks something like this `log.trace("Doing " + foo + " to " + bar);`
The problem is, especially in a hot loop, that throw away string concatenation can ultimately be a performance problem. Especially if `foo` or `bar` have particularly expensive `toString` functions.
The proper way to do something like this in java is either
log.trace("Doing $1 to $2", foo, bar);
or if (log.traceEnabled()) {
log.trace("Doing " + foo + " to " + bar);
}1. Production code running somewhere on a cluster.
2. Released code running somewhere on a end-user's machine.
3. Released production code running somewhere on an end-user's cluster.
And errors happen at weird times, like 3am on a Sunday morning on someone else's cluster. So I'd just as soon not have to wake up, figuring out all the paperwork to get access to some other company's cluster, and then figure out how to attach a debugger. Especially when the error is some non-reproducible corner case in a distributed algorithm that happens once every few months, and the failing process is long gone. Just no.
It is so much easier to ask the user to turn up logging and send me the logs. Nine times out of ten, this will fix the problems. The tenth time, I add more logs and ask the user to keep an eye open.
Especially since a lot of the time an exception being raised is not the actual bug: the bug happened many functions before. By logging key aspects of the state of the program, even in non-error cases, when an error happens, you have a much better chance of piecing together how you got to the error state in the first place.
This is more flexible as it still allows runtime configuration of the logging level.
The OP is simply pointing that some programmers are incompetent and call the trace function incorrectly.
That's not an overhead at all. Even if it were it's not compareable to string concatenation.
Regarding overhead of lambda and copying params. Depends on the language, but usually strings are pass by ref and pass by values are just 1 word long, so we are talking one cycle per variable and 8 bytes of memory. Which were already paid anyways.
That said, logging functions that just take a list of vars are even better, like python's print()
> printtrace("var x and y",x,y)
> def printtrace(*kwargs):
>> print(kwargs) if trace else None
Python gets a lot of slack for being a slow language, but you get so much expressiveness that you can invest in optimization after paying a flat cycle cost.
The problem the OP is pointing out is that some programmers are incompetent and do string concatenation anyway. A mistake which if anything is even easier in Python thanks to string interpolation.
If you want the builtin interpolation to become a noop in the face runtime log disabling then the logging library has to be a builtin too.
A logging framework may have the equivalent of prepared statements. You may also nudge usage where the raw string API is `log.traceRaw(String rawMessage)` while the parametrized one has the nicer naming `log.trace(Template t, param1, param2)`.
There are many ideas if you look at SQL libs. In my example I used a different type but there other solutions. Be creative.
logger.log(new Template("foo"))`
logger.log("foo", [])
logger.prepare("foo").log()You pass "foo" to Template. The Template will be instantiated before log ever sees it. You conveniently left out where the Foo string is computed from something that actually need computation.
Like both:
new Template("doing X to " + thingBeingOperatedOn)
new Template("doing " + expensiveDebugThing(thingBeingOperatedOn))
You just complicated everything to get the same class of error.Heck even the existing good way of doing it, which is less complicated than your way, still isn't safe from it.
logger("doing {}", expensiveDebugThing(thingBeingOperatedOn))
All your examples have the same issue, both with just string concatenation and more expensive calls. You can only get around an unknowing or lazy programmer if the compiler can be smart enough to entirely skip these (JIT or not - a JIT would need to see that these calls never amount to anything and decide to skip them after a while. Not deterministically useful of course).> You conveniently left out where the Foo string is computed from something that actually need computation.
I left it out because the comment I was replying to was pointing that some logs don't have params.
For the approach using a `Template` class, the expectation would be that the doc would call out why this class exists in the first place as to enable lazy computation. Doing string concatenation inside a template constructor should raise a few eyebrows when writing or reviewing code.
I wrote `logger.log(new Template("foo"))` in my previous comment for brevity as it's merely an internet comment and not a real framework. In real code I would not even use stringy logs but structured data attached to a unique code. But since this thread discusses performance of stringy logs, I would expect log templates to be defined as statics/constants that don't contain any runtime value. You could also integrate them with metadata such as log levels, schemas, translations, codes, etc.
Regarding args themselves, you're right that they can also be expensive to compute in the first place. You may then design the args to be passed by a callback which would allow to defer the param computation.
A possible example would be:
const OPERATION_TIMEOUT = new Template("the operation $operationId timed-out after $duration seconds", {level: "error", code: "E_TIMEOUT"});
// ...
function handler(...) {
// ..
logger.emit(OPERATION_TIMEOUT, () => ({operationId: "foo", duration: someExpensiveOperationToRetrieveTheDuration()}))
}
This is still not perfect as you may need to compute some data before the log "just in case" you need it for the log. For example you may want to record the current time, do the operation. If the operation times out, you use the time recorded before the op to compute for how long it ran. If you did not time out and don't log, then getting the current system time is "wasted".All I'm saying is that `logger.log(str)` is not the only possible API; and that splitting the definition of the log from the actual "emit" is a good pattern.
https://typing.python.org/en/latest/spec/literal.html#litera...
For Rust’s macros, a literal can be expressed as `$arg:lit`. This does allow other literals as well, such as int or float literals, but typically the generated code would only work for a string literal.
#define foo(x) ( \
(void)std::integral_constant<char, (x)[0]>::value, \
foo_impl(x) \
)
(the re-evaluation of x doesn't matter if it compiles). You can also use a user-defined literal which has a different ergonomic problem.What metadata? The raw template? That's data in this case, data for the later rendering of logs. Yes, the template plus the params is going to be slightly bigger than a rendered string, but that's the speed/size tradeoff inherent almost everywhere. It may even keep seperate things like the subsystem, event type, log level, etc; which trades off size (again) for speed/ease of filtering. It's all trade-offs, and to blanket declare one method (the Windows method in this case) as just bad design is only displaying your own ignorance, or bias.
You may be misunderstanding something here.
If you follow the varargs-style recommendation, then concatenation occurs in the log class.
If you follow the guard-style recommendation, then the interpolated expressions will not be evaluated unless the log level matches.
In the naive approach, concatenation always occurs and all expressions which are part of the interpolation will be evaluated no matter the log level.
Could it be that you were thinking about StringBuffer vs. concatenation, an entirely unrelated problem?
The former still creates strings, for the garbage collector to mop up even when log.traceEnabled() is false, no?
Also, even if the former or latter is implemented as:
fn trace(log, str, args...) {
if (!log.tracing) return;
// ...
}
Most optimising JIT compilers will code hoist the if-condition when log.tracing is false, anyway.There are a lot of libraries that haven non-idempotent actions. There are a lot of inputs that can be problematic to log, too.
I guess in those cases standard practice is for lib to return a detailed error yeah.
As far as traces, trying to solve issues that depend on external systems is indeed a tall order for your code. Isn't it beyond the scope of the thing being programmed.
Either way logging the input (file name) is notably not sufficient for debugging if the file can change between invocations. The action can be idempotent and still be affected by other changes in the system.
> trying to solve issues that depend on external systems is indeed a tall order for your code. Isn't it beyond the scope of the thing being programmed.
If my program is broken I need it fixed regardless of why it’s broken. The specific example here of a file changing is likely to manifest as flakiness that’s impossible to diagnose without detailed logs from within the library.
I will say that error handling and logging in general is one of my weakpoints, but I made a comment about my approach so far being dbg/pdb based, attaching a debugger and creating breakpoints and prints ad-hoc rather than writing them in code. I'm sure there's reasons why it isn't used as much and logging in code is so much more common, but I have faith that it's a path worth specializing in.
Back to the file reading example, for a non-idempotent function. Considering we are using an encapsulating approach we have to split ourselves into 3 roles. We can be the IO library writer, we can be the calling code writer, and we can be an admin responsible for the whole product. I think a common trap engineers fall for is trying to keep all of the "global" context (or as much as they can handle) at all times.
In this case of course we wouldn't be writing the non-idempotent library, so of course that's not a hat we wear, do not quite care about the innards of the function and its state, rather we have a well defined set of errors that are part of the interface of the function (EINVAL, EACCES, EEXIST).
In this sense we respect the encapsulation boundaries and are provided the information necessary by the library. If we ever need to dive into the actual library code, first the encapsulation is broken and we are dealing with a leaky abstraction, second we just dive into the library code, (or the filesystem admin logs themselves).
It's not precisely the type of responsibility that can be handled at design time and in code anyways, when we code we are wearing the calling-module programmer hat. We cannot think of everything that the sysadmin might need at the time of experiencing an error, we have to think that they will be sufficiently armed with enough tools to gather the information necessary with other tools. And thank god for that! checking /proc/fs and looking at crash dumps, and attaching processes with dbg will yield far better info than relying on whatever print statements you somehow added to your program.
Anyways at least that's my take on the specific example of glibc-like implementations of POSIX file operations like open(). I'm sure the implications may change for other non-idempotent functions, but at some point, talking about specifics is a bit more productive than talking in the abstract.
I generally agree that I would not expect a core library to do a bunch of logging, at least not onto your application logs. This stuff generally is very stable with a clean interface and well defined error reporting.
But there’s a whole world of libraries that are not as clean, not as stable, and not as well defined. Most libraries in my experience are nowhere near as clean as standard IO libraries. They often do very complex stuff to simplify for the calling application and have weakly defined error behavior. The more complexity a library contains, the more it likely has this issue. Arguably that is leaky abstraction but it’s also the reality of a lot of software and I’m not even sure that’s a bad thing. A good library that leaks in unexpected conditions might be just fine for many real world purposes.
I guess my experience is more from the role of a startup or even in-house software. So we both develop and operate the software. But in scenarios where you ship the software and it's operated by someone else, it makes sense to have more auditable and restricted logging instead of all-too-powerful ad-hoc debugging.
It is very, very common that the code that you have written isn't even the code that executes. It gets modified by enterprise anti virus or "endpoint security". All too often do I see "File.Open" calls return true that the caller has access, but actually what's happened is AV has intercepted the call, blocked it improperly, and returns 0 bytes file that exists (even though there is actually a larger file there) instead of saying the file cannot open.
I will never, in a million years, be granted access to attach a debugger to such a client computer. In fact, they will not even initially disclose that they are using anti virus. They will just say the machine is set up per company policy and that your software doesn't work, fix it. The assumption is always that your software is to blame and they give you nearly nothing, except for the logs.
The only way I ever get this solved in a reasonable amount of time is by looking at verbose logs, determining that the scenario they have described is impossible, explaining which series of log messages is not able to occur, yet occurred on their system, and ask them to investigate further. Usually this ends up being closed with a resolution like "Checked SuperProtectPro360 logs and found it was writing infernal error logs at the same time as using the software. Adjusted the monitoring settings and problem is now resolved."
Second, it can lose information about at what exact time and in what exact order things happened. For example, cleanup operations during stack unwinding can also produce log messages, and then it’s not clear anymore that the original error happened before those.
Even when you include a timestamp at each level, that’s often not sufficient to establish a unique ordering, unless you add some sort of unique counter.
It gets even more complicated when exceptions are escalated across thread boundaries.
Personally I don't mind it... the whole "$outer: $inner" convention naturally lends to messages that still parse in my brain and actually include the details in a pretty natural way. Something like:
"Error starting up: Could not connect to database: Could not read database configuration: Could not open config file: Permission denied"
Tells me the config file for the database has broken permissions. Because the permission denied error caused a failure opening the config file, which caused a failure reading the database configure, which caused a failure connecting to the database, which caused an error starting up. It's deterministic in that for "$outer: $inner", $inner always caused $outer.
Maybe it's just experience though, in a sense that it takes a lot of time and familiarity for someone to actually prefer the above. Non-technical people probably hate such messages and I don't necessarily blame them.
Should if throw an exception for that to let you know, or should it gracefully fallback so your service stays alive ? The middle ground is leaving a log and chugging along, your proposition throws that out of the window.
Errors are massaged for the reader - a database access library will know that a DNS error occurred and that is (the first step for debugging) why it cannot connect to the specified datastore. The service layer caller does not need to know that there is a DNS error, it just needs to know that the specified datastore is uncontactable (and then it can move on to the approriate resilience strategy, retry that same datastore, fallback to a different datastore, or tell the API that it cannot complete the call at all).
The caller can then decide what to do (typically say "Well, I tried, but nothing's happening, have yourself a merry 500)
It makes no sense for the Service level to know the details of why the database access layer could not connect, no more than it makes any sense for the database access layer to know why there is a DNS configuration error - the database access just needs to log the reasons (for humans to investigate), and tell the caller (the service layer) that it could not do the task it was asked to do.
If the service layer is told that the database access layer encountered a DNS problem, what is it going to do?
Nothing, the best it can do is log (tell the humans monitoring it) that a DB access call (to a specific DB service layer) failed, and try something else, which is a generic strategy, one that applies to a host of errors that the database call could return.
I'll accept that it is a security problem; why would it be a serious security problem? Any error that the client knows about the configuration is unlikely to be one that is exploitable anyway, and if it is (for example, the client gets told "could not connect to 192.168.1.139:5432"), then you have bigger problems than sending error messages to clients.
What sort of example did you have in mind that makes this a serious security problem?
Technical infrastructure details: Database types, versions, server configurations File paths and directory structures: Enabling directory traversal attacks Programming logic: Including code snippets that expose application behavior Sensitive credentials: Database connection strings, usernames, passwords Software versions: Allowing attackers to identify known vulnerabilities The impact of this vulnerability is significant. Error messages can expose not just that a system runs PHP, but that it runs a specific, unsupported version — providing attackers with a clear exploitation path.
Security researchers have documented numerous instances where verbose error messages enabled breaches:
Dating App Vulnerability (2016): Tinder’s login system displayed error messages indicating whether specific email addresses were registered, enabling brute-force attacks to identify valid accounts. Password Manager Leak (2019): A popular password manager’s login form disclosed through error messages whether email addresses were registered with the service, facilitating targeted attacks. Government Agency Breach (2020): A major US government agency’s website displayed error messages revealing whether specific usernames existed in the system, enabling attackers to enumerate valid accounts.
[1] https://medium.com/@instatunnel/security-misconfiguration-th...
I mean, sure, it's a security issue, but on a scale of 1-10, with 1 being "security issue, we'll fix in next point release" and 10 being "All-hands until this emergency patch goes out, and we keep the system offline while fixing it", this is definitely a 1.
Secondly, this barely counts as a security issue; some systems I worked on recently required error messages to tell the user how to fix the error they got. You don't simply say (for example) "attachment not found", you say "Field $FIELD is empty. This is a mandatory field" or similar.
There are still plenty of secure systems out there that will direct the user to create an account if an unregistered user attempts to log in.
It's a trade-off in usability: some places go the "Authentication failed (but we won't tell you why)" route, and others go the "Click here to sign up" route.
Jesus no.
Aside from this now being an argument on semantics, someone enumerating every customer/user account you have is serious.
It opens the door for privacy leaks, targeted attacks (like password attempts, phishing, or account lockouts)
If you don't want to take that seriously, thank you for your honesty, I will ensure that I never have an account on any service you work on.
That's fine; you already have multiple accounts on various providers that can be trivially massaged by a client into providing proof of life of an email address.
Microsoft, OpenAI, Anthropic, Oracle, Amazon; I tried them all now, and they let you enumerate emails trivially by clicking "signup" and then informing you if you choose an email that is already registered.
> Jesus no.
You haven't really has thought this through as thoroughly as you think you have - email enumeration is still, at the tail end of 2025, possible across all major sites, providers, etc.
Then catch the exception on the backup path and wrap it in a custom exception that conveys to the handler the fact that you were on the backup path. Then throw the new exception.
Even relatively complex operations like say convert this document into a PDF etc basically only has two useful states either it worked or something specific failed at which point just tell me that thing.
Now independent software like web servers or database can have useful logs because they have completely independent interfaces with the outside world. But I call libraries they don’t call me.
Any library can do a bad job here, that doesn’t come down to logging vs error messages.
Really the only thing we can defiantly say is when both approaches are executed well it’s harder to use log entries in your code. If something returns an error that’s tied to a specific call to a specific bit of code, where a log entry could in theory be from anything etc.
Of course they shouldn't just be dumping text to stdout/stderr, but as long as the library logging is optional (or only logs when the library has reached some kind of unrecoverable state with instructions to file a bug report), logging is often the right call.
It's easier to have logs and turn them off at compile time/runtime than to not have logs and need them once deployed.
You don't want to throw because destroying someone's production isn't worth it. You don't want to silent continue in that state because realistically there's no way for application owner to understand what is happening and why.
One test case here is that your library has existed for a decade and was fast, but Java removed a method that let you make it fast, but you can still run slow without that API. Java the runtime has a flag that the end use can enable to turn it back on a for a stop gap. How do you expect this to work in your model, you expect to have an onUnnecessarilySlow() callback already set up that all of your users have hooked up which is never invoked for a decade, and then once it actually happens you start calling it and expect it to do something at all sane in those systems?
Second example is all of the scenarios where you're some transitively used library for many users, it makes and callback strategy immediately not work if the person who needs to know about the situation and could take action is the application owner rather than the people writing library code which called you. It would require every library to offer these same callbacks and transitively propagate things, which would only work if it was just such a firm idiomatic pattern in some language ecosystem and I don't believe that it is in any language ecosystem.
>but Java removed a method that let you make it fast, but you can still run slow without that API
I’d like to see an example of that, because this is extremely hypothetical scenario. I don’t think any library is so advanced to anticipate such scenarios and write something to log. And of course Java specifically has longer cycle of deprecation and removal. :)
As for your second example, let’s say library A is smart and can detect certain issues. Library B depending on it is at higher abstraction level, so it has enough business context to react on them. I don’t think it’s necessary to propagate the problem and leak implementation details in this scenario.
https://github.com/protocolbuffers/protobuf/issues/20760
Java Protobuf also logs a warning now if you can tell you are using gencode old enough that it's covered by a DoS CVE. They actually did a release that broke compatability of the CVE covered gencode but restored it and print a warning in a newer release.
Java 8 is still really popular, probably the most popular single version. It's not just servers in context, but also Android where Java 8 is the highest safe target, it's not clear what decade we'll be in when VarHandle would be safe to use there at all.
VarHandle was Java 9 but MemorySegment was Java 17. And the rest of FFM is only in 25 which is fully bleeding edge.
Protobuf may realistically try to move off of sun.misc.unsafe without the performance regressions in a way that is without adopting MemorySegment to avoid the versioning problem, but it takes significant and careful engineering time.
That said it's always possible to have waterfall of preferred implementations based on what's supported, it's just always an implementation/verification costs.
It’s very rarely realistic that a client would code up meaningful paths for every possible failure mode in a library. These callbacks are usually reserved for expected conditions.
Yes, that’s the point. You log it until you encounter it for the first time, then you know more and can do something meaningful. E.g. let’s say you build an API client and library offers callback for HTTP 429. You don’t expect it to happen, so just log the errors in a generic handler in client code, but then after some business logic change you hit 429 for the first time. If library offers you control over what is going to happen next, you may decide how exactly you will retry and what happens to your state in between the attempts. If library just logs and starts retry cycle, you may get a performance hit that will be harder to fix.
I would much prefer a library have sane defaults, reasonable logging, and a way for me to plug in callbacks where needed. Writing On429 and a hundred other functions that just point to Logger.Log is not a good use of time.
I still don’t want to have to provide a 429 callback just to log, though. The library should log by default if the callback isn’t registered.
var client = aClient()
.onError((request,response) -> {
LOG.debug(…);
return FAIL;
}).build();
And eventually you do this: return switch(response.code()) {
case 429 -> RETRY;
default -> FAIL;
}
Or something more interesting, e.g. with more details of retry strategy.Warnings are just errors that no one wants to deal with.
mostly though when you are on a known problem warnings should be a useful filter to find where in the logs the problem might have started, then you use that timestamp to find info logs in the same area
Anything that has a measurable impact on production should be logged above that, except if your system ignores log levels in the first place, but that's another can of worms.
The application owner should be able to adjust the contexts up or down. This is the point of ownership and where responsibility over which logs matter is handled.
A library author might have ideas and provide useful suggestions, but it's ultimately the application owner who decides. Some libraries have huge blast radius and their `error` might be your `error` too. In other contexts, it could just be a warning. Library authors should make a reasonable guess about who their customer is and try to provide semantic, granular, and controllable failure behavior.
As an example, Rust's logging ecosystem provides nice facilities for fine-grained tamping down of errors by crate (library) or module name. Other languages and logging libraries let you do this as well.
That capability just isn't adopted everywhere.