8 ms·

In Java? Surely one of the benefits of the JIT is to compile logger.debug() into a no-op if the log level is not high enough.

clon 5y ago
You would still be doing the job of concatenating together the error message, possibly rendering some complex objects to a string, that is then fed to the no-op. The point parent was making is that there is also a performance aspect to this, in addition to the security aspect.
- chrisseaton 5y ago
  > You would still be doing the job of concatenating together the error message, possibly rendering some complex objects to a string, that is then fed to the no-op. Why would you still do be doing that work? If a value goes into a no-op, then the value isn't computed. (In theory - I'm sure it doesn't always work out 100% of the time in practice.)
  - christophilus 5y ago
    Unless the JVM is sure the logic is not effectful, it couldn’t eliminate it.
    - chrisseaton 5y ago
      The JVM knows what string concatenation does.
      - envp 5y ago
        But what if one of the arguments is a function call? Then it isn't easy to prove there are no side effects
        chrisseaton 5y ago
        If it’s too big to in-line then yes.
        vlovich123 5y ago
        That’s says absolutely nothing about whether the function has a side effect.
        chrisseaton 5y ago
        If you can inline it into the compilation unit, then you can see if it has side effects or not.
        deleted 5y ago
        [deleted]
      - alserio 5y ago
        Isn't the point that you don't generally stuff your log of things that are only strings but of things that can become strings? (Asking since I know of your work with truffle)
        chrisseaton 5y ago
        I assumed things like the names of resources that are already strings because you’re using them in the actual program?
        alserio 5y ago
        A typical logger.info("user {} did the thing", user) can skip the actual string interpolation and user value stringification, if the log level is not > info. However, logger.info("user " + user + " did the thing") cannot avoid at least the execution of user.toString(), even after jit optimizations, unless the jit could prove that toString does not have side effects. But I don't believe the jvm jit tries to do that. Am I wrong?
        chrisseaton 5y ago
        If user is a string, then #toString() is a trivial method, will inline, and become a no-op.
        alserio 5y ago
        However, if user happened be an user-defined User object it would be hard to guarantee that it could be inlined
        chrisseaton 5y ago
        Yes
      - christophilus 5y ago
        `"hello" + myFooObject.toString()` Can you eliminate that? It's impossible to say without knowing whether or not `myFooObject.toString()` is effectful. Maybe the JVM can make that assessment. Maybe not. I don't know, but it's not as trivial as "knowing what string concatenation does".
        deleted 5y ago
        [deleted]
        deleted 5y ago
        [deleted]
        sour-taste 5y ago
        A straightforward way to do this is for Java to assume built in types like strings are side effect free, but custom types may not be. This would likely cover a good portion of log lines but not all, obviously.
      - unclebucknasty 5y ago
        The noop determination is made during runtime within the log method called. So, it's LOG.info(obj.toString()), wherein that method inspects the log level setting, then decides whether to ignore. Are you saying that Java does or should "optimize" in such a way that it branches to the logic within each method called during runtime, inspects which code would be executed per possibly mutable runtime values (like log level), considers possible side effects (in-method and in parameters) then decides whether to even invoke the method at all?
    - mumblemumble 5y ago
      There's an even simpler reason why the JIT compiler can't prune it: it's possible to dynamically change the logging level at run time.
      - barrkel 5y ago
        That is actually a reason that a JIT compiler can prune where an AOT compiler can't. JIT can deoptimize when assumptions change. One of the bigger wins with the JVM is assuming that a virtual method can be called statically if there are no derived classes. That's a huge win for every leaf class in the class tree. The assumption can change every time a class is loaded of course. The optimization is called devirtualization and it can be combined with inlining to get even bigger wins.
        mumblemumble 5y ago
        Fair point... but it seem like, even so, doing that to monitor whether a single integer variable might change sounds like a lot of added complexity. Are there other use cases that would help to justify it? Reducing the impact of failing to follow logging best practices doesn't seem like an obviously sufficient cause.
        chrisseaton 5y ago
        It's a standard part of the JVM https://docs.oracle.com/javase/7/docs/api/java/lang/invoke/SwitchPoint.html https://docs.oracle.com/javase/7/docs/api/java/lang/invoke/S....
isbvhodnvemrwvn 5y ago
Logger levels are mutable to allow switching them at runtime, JIT can not make an assumption that the log level will stay the same.
- akvadrako 5y ago
  Sure it can, since the JIT has access to runtime information and all the code. It could reorder the steps so first the log level is checked, then that block is run.
  - hamburglar 5y ago
    log.debug(“foo count: “ + fooHandler.incrementAndReturnFooCount()); Should the JIT call incrementAndReturnFooCount if debug logs are disabled? This is a long-recognized pitfall of C preprocessor macros that look like function calls but may simply be defined away, causing unexpected behavior.
    - akvadrako 5y ago
      It should call it if it has side effects, otherwise not. Java isn't C; the runtime can be a lot smarter.
      - hamburglar 5y ago
        I guess I’m not up on the state of the art with respect to the JRE’s ability to determine whether arbitrary code has side effects. That’s quite a broad problem. If I write fizzbuzz but use log.debug for output, does it optimize my main() to be empty unless I run it with debug enabled?
- alserio 5y ago
  I believe the problem is just that the toString methods implicitly called when concatenating strings and objects, can execute side effects. And the JIT has to keep those effects if it cannot prove they are just heating up your CPU
millerm 5y ago
How could it? The log level is not a constant. It is evaluated at runtime, every time. You can’t compile that out. Am I wrong?
- alserio 5y ago
  The JIT works by making assumptions using runtime information, and by discarding compiled code when the conditions change and the assumptions are not valid anymore.
vbezhenar 5y ago
JVM is not that smart.

clon 5y ago

You would still be doing the job of concatenating together the error message, possibly rendering some complex objects to a string, that is then fed to the no-op. The point parent was making is that there is also a performance aspect to this, in addition to the security aspect.

chrisseaton 5y ago
> You would still be doing the job of concatenating together the error message, possibly rendering some complex objects to a string, that is then fed to the no-op. Why would you still do be doing that work? If a value goes into a no-op, then the value isn't computed. (In theory - I'm sure it doesn't always work out 100% of the time in practice.)
- christophilus 5y ago
  Unless the JVM is sure the logic is not effectful, it couldn’t eliminate it.
  - chrisseaton 5y ago
    The JVM knows what string concatenation does.
    - envp 5y ago
      But what if one of the arguments is a function call? Then it isn't easy to prove there are no side effects
      - chrisseaton 5y ago
        If it’s too big to in-line then yes.
        vlovich123 5y ago
        That’s says absolutely nothing about whether the function has a side effect.
        chrisseaton 5y ago
        If you can inline it into the compilation unit, then you can see if it has side effects or not.
        deleted 5y ago
        [deleted]
    - alserio 5y ago
      Isn't the point that you don't generally stuff your log of things that are only strings but of things that can become strings? (Asking since I know of your work with truffle)
      - chrisseaton 5y ago
        I assumed things like the names of resources that are already strings because you’re using them in the actual program?
        alserio 5y ago
        A typical logger.info("user {} did the thing", user) can skip the actual string interpolation and user value stringification, if the log level is not > info. However, logger.info("user " + user + " did the thing") cannot avoid at least the execution of user.toString(), even after jit optimizations, unless the jit could prove that toString does not have side effects. But I don't believe the jvm jit tries to do that. Am I wrong?
        chrisseaton 5y ago
        If user is a string, then #toString() is a trivial method, will inline, and become a no-op.
        alserio 5y ago
        However, if user happened be an user-defined User object it would be hard to guarantee that it could be inlined
        chrisseaton 5y ago
        Yes
    - christophilus 5y ago
      `"hello" + myFooObject.toString()` Can you eliminate that? It's impossible to say without knowing whether or not `myFooObject.toString()` is effectful. Maybe the JVM can make that assessment. Maybe not. I don't know, but it's not as trivial as "knowing what string concatenation does".
      - deleted 5y ago
        [deleted]
      - deleted 5y ago
        [deleted]
      - sour-taste 5y ago
        A straightforward way to do this is for Java to assume built in types like strings are side effect free, but custom types may not be. This would likely cover a good portion of log lines but not all, obviously.
    - unclebucknasty 5y ago
      The noop determination is made during runtime within the log method called. So, it's LOG.info(obj.toString()), wherein that method inspects the log level setting, then decides whether to ignore. Are you saying that Java does or should "optimize" in such a way that it branches to the logic within each method called during runtime, inspects which code would be executed per possibly mutable runtime values (like log level), considers possible side effects (in-method and in parameters) then decides whether to even invoke the method at all?
  - mumblemumble 5y ago
    There's an even simpler reason why the JIT compiler can't prune it: it's possible to dynamically change the logging level at run time.
    - barrkel 5y ago
      That is actually a reason that a JIT compiler can prune where an AOT compiler can't. JIT can deoptimize when assumptions change. One of the bigger wins with the JVM is assuming that a virtual method can be called statically if there are no derived classes. That's a huge win for every leaf class in the class tree. The assumption can change every time a class is loaded of course. The optimization is called devirtualization and it can be combined with inlining to get even bigger wins.
      - mumblemumble 5y ago
        Fair point... but it seem like, even so, doing that to monitor whether a single integer variable might change sounds like a lot of added complexity. Are there other use cases that would help to justify it? Reducing the impact of failing to follow logging best practices doesn't seem like an obviously sufficient cause.
        chrisseaton 5y ago
        It's a standard part of the JVM https://docs.oracle.com/javase/7/docs/api/java/lang/invoke/SwitchPoint.html https://docs.oracle.com/javase/7/docs/api/java/lang/invoke/S....

isbvhodnvemrwvn 5y ago

Logger levels are mutable to allow switching them at runtime, JIT can not make an assumption that the log level will stay the same.

akvadrako 5y ago
Sure it can, since the JIT has access to runtime information and all the code. It could reorder the steps so first the log level is checked, then that block is run.
- hamburglar 5y ago
  log.debug(“foo count: “ + fooHandler.incrementAndReturnFooCount()); Should the JIT call incrementAndReturnFooCount if debug logs are disabled? This is a long-recognized pitfall of C preprocessor macros that look like function calls but may simply be defined away, causing unexpected behavior.
  - akvadrako 5y ago
    It should call it if it has side effects, otherwise not. Java isn't C; the runtime can be a lot smarter.
    - hamburglar 5y ago
      I guess I’m not up on the state of the art with respect to the JRE’s ability to determine whether arbitrary code has side effects. That’s quite a broad problem. If I write fizzbuzz but use log.debug for output, does it optimize my main() to be empty unless I run it with debug enabled?
alserio 5y ago
I believe the problem is just that the toString methods implicitly called when concatenating strings and objects, can execute side effects. And the JIT has to keep those effects if it cannot prove they are just heating up your CPU

millerm 5y ago

How could it? The log level is not a constant. It is evaluated at runtime, every time. You can’t compile that out. Am I wrong?

alserio 5y ago
The JIT works by making assumptions using runtime information, and by discarding compiled code when the conditions change and the assumptions are not valid anymore.

vbezhenar 5y ago

JVM is not that smart.