reduce some codegen costs #36600

vtjnash · 2020-07-09T20:57:07Z

Alter some patterns and thresholds that can be causes of minor code bloat.

(partly related to #34270)

JeffBezanson · 2020-07-09T21:27:27Z

Ah, also implements #36236?

vtjnash · 2020-07-09T21:30:52Z

No, this doesn't implement any part of #36236 (which would require making closures, and would generally thus be rather expensive at compile and run time)

JeffBezanson · 2020-07-09T21:52:09Z

I was thinking of #36236 (comment); some similar ideas.

oxinabox · 2020-07-10T10:11:05Z

@c42f and I were talking about this in the context of FluxML/Zygote.jl#88 (comment)
where @warn and @info etc were breaking Zygote.

vtjnash · 2020-07-10T14:26:56Z

That comment talks about how to use closures to redesign the behavior of logging system, this does not do that and just optimizes the implementation. There's overlap only in that it talks about how sometimes the closures that are allocated would be simple in some of the same cases that I optimize here.

vtjnash · 2020-07-10T15:20:27Z

@nanosoldier runbenchmarks(ALL, vs=":master")

base/logging.jl

nanosoldier · 2020-07-10T23:21:39Z

Your benchmark job has completed - possible performance regressions were detected. A full report can be found here. cc @ararslan

oxinabox · 2020-07-11T18:53:10Z

That comment talks about how to use closures to redesign the behavior of logging system, this does not do that and just optimizes the implementation. There's overlap only in that it talks about how sometimes the closures that are allocated would be simple in some of the same cases that I optimize here.

Yes, we don't have written of the exact discussion anywhere anymore. Slack ate it.
It was related to that issue, but not recorded in that issue.
But it was very much this PR, identifying if a @warn had only simple types, and if so not entering the code-path that has exception handling.
So I think this is a good design, because it aligns with our thoughts

base/logging.jl

oxinabox · 2020-07-11T18:57:05Z

base/logging.jl

+    val isa Number && return true
+    if val isa Expr
+        val.head === :quote && val[1] isa Symbol && return true
+        val.head === :inert && return true


Do you want to catch tuple and vector and matrix literals where the head is vect tuple etc,
and the args are all themselves issimple

not really, no

c42f · 2020-07-13T23:29:40Z

That comment talks about how to use closures to redesign the behavior of logging system, this does not do that and just optimizes the implementation.

Actually the changes proposed there were motivated firstly by a desire to improve the implementation (as requested in the OP of that issue) and then later, possibly, to use that to improve the interface. So I'd say this PR is very much in line with what I was wanting to do, and in the order I was imagining doing it 👍

c42f

Largely looks good to me, I'm very much on board with removing these try-catch in the particular way which is done here. Needs tests covering the various cases of message code generation

I'd point out that there's one semantic change introduced here, which is that errors arising from the logger are no longer caught. I think this is a good improvement though, as catching errors from the logger (rather than the message generation) was a misfeature of the previous design.

c42f · 2020-07-13T06:41:29Z

base/logging.jl

+    msg = try
+              "Exception while generating log record in module $_module at $filepath:$line"
+          catch ex
+              "Exception handling log message: $ex"


Ideally I think we should avoid any nontrivial code in the final fallback code path of message formatting — even formatting the exception — as that itself could cause another exception. The point is that the application should never crash due to broken message formatting.

Suggested change

"Exception handling log message: $ex"

"Exception handling log message: " * try "$ex" catch ; "<unprintable>" end

No, we can't just keep going deep down the error chain. Eventually you have to admit you've broken everything.

The point is to fall back to emitting a message which can't depend on user-defined code (formatting "$ex" can still run user code).

We can clearly do this. I think you're asserting that you don't want to?

Your "correction" still depends on user-defined code being valid, so, yes, clearly we can't do that. The subsequent lines of code need to run yet more user-defined code (and more complex code) so there's little point in adding try/catch here while forgetting to handle most of the actual sources of errors.

Seems we're talking past each other here in some way, because I don't understand this statement.

Let me attempt to spell out my reasoning very explicitly.

The following code formats potentially user defined types in both branches, and these arise from the logging macro

msg = try # The user may have passed some odd type for _module or filepath or line here # so this may fail. "Exception while generating log record in module $_module at $filepath:$line" catch ex # `ex` here is the potentially-user-defined exception resulting from running user-defined `string` functions, # so may fail. # Granted, this is unlikely "Exception handling log message: $ex" end

The following invocation of user-defined code is related to the installed logger (which may internally protect itself with a try-catch of its own, should it so choose)

handle_message( logger, Error, msg, _module, :logevent_error, id, filepath, line; exception=err)

So to me it seems there's a clear separation of the user code which

emits the log record, vs

consumes the log record

and the former is what I'm arguing should be wrapped in various stupidly-nested try-catch statements.

"protect" is just a relatively useless concept here, so I'm intentionally not attempting to pretend to do it excessively

Well I don't understand that comment; saying it's a "useless concept" just leaves me guessing here which is a bit disappointing. I want to know the why here, not what.

But anyway, the actual technicality here is not a hill I'm willing to die on.

base/logging.jl

c42f · 2020-07-13T23:28:54Z

stdlib/Logging/src/ConsoleLogger.jl

@@ -96,38 +96,41 @@ function termlength(str)
 end

 function handle_message(logger::ConsoleLogger, level, message, _module, group, id,
-                        filepath, line; maxlog=nothing, kwargs...)


Why remove maxlog=nothing from here? It seems to make the code below rather more complicated.

Saves the compiler/frontend from needing to create a keyword sorter and corresponding structdiff methods

I don't understand why this is worthwhile... unless something about this API forces the amount of compiler work to scale with the number of logging statements in the program?

Is the point that kwargs can have many different types (one per logging statement) and that leads to trouble?

If so that connects to another idea I've been thinking about: That perhaps we should be using a data structure more like Dict{Symbol,Any}, or ImmutableDict{Symbol,Any} for passing the key-value pairs of log records rather than (ab)using keyword arguments?

With this change, kwargs can already be (already is) an AbstractDict{Symbol,<:Any}, without making any further changes to the code

vtjnash · 2020-07-14T00:09:55Z

I'd point out that there's one semantic change introduced here, which is that errors arising from the logger are no longer caught. I think this is a good improvement though, as catching errors from the logger (rather than the message generation) was a misfeature of the previous design.

Thanks for highlighting that change. I'd meant to do that as I was typing the change, and apparently forgot to add that to the issue text here.

c42f

I think this is fine. Just needs tests covering the various codegen cases in logmsg_code.

vtjnash · 2020-09-02T02:46:33Z

What are you expect there is to test? The idea here is that these are common enough patterns that they're already being tested, and this just optimizes them.

c42f · 2020-09-02T04:53:53Z

What are you expect there is to test?

That @info msg a=x throws an UndefVarError when either msg or x are undefined. And that this can be caught by the logger.

These are now handled by special case code paths which I doubt we have any tests to cover.

vtjnash · 2020-09-03T15:55:25Z

Ah, that's what you meant. Okay, added.

c42f

I appreciate the extra tests, thanks.

Added in #22210 (and earlier begun in #20853), this is no longer necessary to avoid heap allocations, and thus serves little purpose now.

If we have not eliminated them already, codegen is unlikely to do so as well.

This should avoid the try/catch in some cases, where the message is simply a constant value or simple variable. It also tries to slightly reduce required specialization in some other cases too.

c42f · 2020-09-23T07:00:26Z

I went ahead and rebased this to fix the conflicts. Should we merge it?

vtjnash requested review from c42f and JeffBezanson July 9, 2020 20:57

vtjnash commented Jul 10, 2020

View reviewed changes

base/logging.jl Outdated Show resolved Hide resolved

oxinabox reviewed Jul 11, 2020

View reviewed changes

base/logging.jl Show resolved Hide resolved

oxinabox reviewed Jul 11, 2020

View reviewed changes

vtjnash force-pushed the jn/codegen-costs branch from 976ae1b to d2f6e9a Compare July 13, 2020 19:55

c42f reviewed Jul 13, 2020

View reviewed changes

vtjnash force-pushed the jn/codegen-costs branch from d2f6e9a to 68aad67 Compare July 20, 2020 20:07

c42f requested changes Jul 24, 2020

View reviewed changes

vtjnash force-pushed the jn/codegen-costs branch from 68aad67 to 83fb63d Compare September 1, 2020 20:02

vtjnash force-pushed the jn/codegen-costs branch from 83fb63d to e7ea9b2 Compare September 3, 2020 15:54

vtjnash force-pushed the jn/codegen-costs branch from e7ea9b2 to 6ea26e3 Compare September 3, 2020 16:56

c42f approved these changes Sep 4, 2020

View reviewed changes

vtjnash added 3 commits September 23, 2020 16:29

inlining: remove bonus for Tuple return with heap references

2ca0cc9

Added in #22210 (and earlier begun in #20853), this is no longer necessary to avoid heap allocations, and thus serves little purpose now.

inlining: add non-zero costs to type operations

b77f400

If we have not eliminated them already, codegen is unlikely to do so as well.

logging: avoid try/catch when the message is a simple

f7adc9e

This should avoid the try/catch in some cases, where the message is simply a constant value or simple variable. It also tries to slightly reduce required specialization in some other cases too.

c42f force-pushed the jn/codegen-costs branch from 6ea26e3 to f7adc9e Compare September 23, 2020 06:59

vtjnash merged commit ee93bd8 into master Sep 23, 2020

vtjnash deleted the jn/codegen-costs branch September 23, 2020 15:07

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

reduce some codegen costs #36600

reduce some codegen costs #36600

vtjnash commented Jul 9, 2020 •

edited

Loading

JeffBezanson commented Jul 9, 2020

vtjnash commented Jul 9, 2020

JeffBezanson commented Jul 9, 2020

oxinabox commented Jul 10, 2020

vtjnash commented Jul 10, 2020

vtjnash commented Jul 10, 2020

nanosoldier commented Jul 10, 2020

oxinabox commented Jul 11, 2020

oxinabox Jul 11, 2020

vtjnash Jul 13, 2020

c42f commented Jul 13, 2020

c42f left a comment •

edited

Loading

c42f Jul 13, 2020

vtjnash Jul 13, 2020

c42f Jul 14, 2020 •

edited

Loading

vtjnash Jul 14, 2020

c42f Jul 14, 2020 •

edited

Loading

vtjnash Jul 23, 2020

c42f Jul 24, 2020

c42f Jul 13, 2020

vtjnash Jul 14, 2020

c42f Jul 14, 2020

vtjnash Jul 14, 2020

vtjnash commented Jul 14, 2020

c42f left a comment

vtjnash commented Sep 2, 2020

c42f commented Sep 2, 2020

vtjnash commented Sep 3, 2020

c42f left a comment

c42f commented Sep 23, 2020

	"Exception handling log message: $ex"
	"Exception handling log message: " * try "$ex" catch ; "<unprintable>" end

reduce some codegen costs #36600

reduce some codegen costs #36600

Conversation

vtjnash commented Jul 9, 2020 • edited Loading

JeffBezanson commented Jul 9, 2020

vtjnash commented Jul 9, 2020

JeffBezanson commented Jul 9, 2020

oxinabox commented Jul 10, 2020

vtjnash commented Jul 10, 2020

vtjnash commented Jul 10, 2020

nanosoldier commented Jul 10, 2020

oxinabox commented Jul 11, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

c42f commented Jul 13, 2020

c42f left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

c42f Jul 14, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

c42f Jul 14, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vtjnash commented Jul 14, 2020

c42f left a comment

Choose a reason for hiding this comment

vtjnash commented Sep 2, 2020

c42f commented Sep 2, 2020

vtjnash commented Sep 3, 2020

c42f left a comment

Choose a reason for hiding this comment

c42f commented Sep 23, 2020

vtjnash commented Jul 9, 2020 •

edited

Loading

c42f left a comment •

edited

Loading

c42f Jul 14, 2020 •

edited

Loading

c42f Jul 14, 2020 •

edited

Loading