[WIP] More flexible and convenient logging #23712

c42f · 2017-09-14T15:57:31Z

Here's a WIP for making julia logging systematic, flexible and fast, as described in part in the logging julep, and currently being prototyped in MicroLogging.jl. It turns out that there's quite a few disparate mechanisms in use already for logging in Base, so this WIP is about looking at each use case in turn. Attacking depwarn has been particularly entertaining, and I think the result so far is faster and significantly more accurate. As a side effect of this work, I think we should be easily able to generate a depwarn report after any given julia run with a precise list of locations to fix.

As a whole this is probably not that close to merging yet, but a lot of the key pieces are in place. There's a design tracker over at c42f/MicroLogging.jl#5 with more detail on unanswered issues.

I've included only a bare minimum of log formatting machinery here with the idea that this is better done in a standard library package. With that in mind, I'd suggest checking out the MicroLogging master branch for logs which are actually formatted in a readable way for interactive work.

ggggggggg · 2017-09-14T17:31:04Z

base/logging.jl

+# itself.
+struct LogState
+    min_enabled_level::LogLevel
+    logger::AbstractLogger


Isn't this not concretely typed?

LogState itself is a leaf type; AbstractLogger is not. This is arranged so that some minimal part of the state (only min_enabled_level at the moment, but possibly some additional things) is accessible without generic dispatch.

I think I get it, you concretely typed as much as possible, but logger can't be concretely typed if you want to be able to change it easily?

Exactly. The design problem is to decide which aspects of log filtering are sufficiently useful and fast that every user defined logger must support them - those can be cached in the concretely typed log state, and inlined at the call site.

ggggggggg · 2017-09-14T17:31:23Z

base/logging.jl

+const _min_enabled_level = Ref(Debug)
+
+
+# A concretely typed cache of data extracted from the logger, plus the logger


Most of these comments look like they should be docstrings.

The convention I'm using is that implementation details have comments but no docstrings. How is this generally handled in Base? I don't want to give people the idea that Logging.LogState (for example) is part of the public API.

That seems sensible. A quick browse shows me that there is a non-exported function in Enums.jl with a comment rather than a doc-string, so it seems similar to what you're doing.

c42f · 2017-09-24T04:16:46Z

Hmm, mysterious - it looks like #17997 broke something I was doing on this branch. ~~I'm now getting odd errors regarding is_root_module during bootstrap even after rebasing locally and fixing some conflicts.~~ [Edit - long since rebased & fixed]

helgee · 2017-10-24T12:41:41Z

base/libgit2/merge.jl

@@ -219,13 +219,13 @@ function merge!(repo::GitRepo, anns::Vector{GitAnnotated}, fastforward::Bool;
    elseif ffpref == Consts.MERGE_PREFERENCE_FASTFORWARD_ONLY
        if isset(ma, Cint(Consts.MERGE_ANALYSIS_FASTFORWARD))
            if length(anns) > 1
-                warn("Unable to perform Fast-Forward merge with mith multiple merge heads.")
+                @warn "Unable to perform Fast-Forward merge with mith multiple merge heads." repo


Not your fault, but "with mith"? 😂

s/with mith/mit

;) 🇩🇪

Some minor edits here to make things suitable for Base.

Use handle_message rather than dispatch_message, as not all message handling is pure dispatch (the message may be stored rather than sent elsewhere). Reuse the name dispatch_message internally.

* Forward depwarn() calls to new backend * Use caller frame pointer as message id. This makes initial first-pass deduplication of depwarns quite a lot faster. * Change --depwarn=error to --depwarn=throw for clarity * Introduce defines for log levels into julia.h

Forward all frontend depwarn messages through to the julia logging system for consistency of formatting and dispatch. Deciding whether a depwarn should appear as an thrown error is also now handled outside flisp to keep this decision in one place where possible. Detail: * Ensure that deprecation-message forwards to the logging system. Also include file and line number metadata * Remove jl_parse_depwarn(), flisp *depwarn* and related scheme code as this can be handled on the julia side. * Rename syntax_deprecation_warnings(false) to without_syntax_deprecations, as this was only ever used to turn syntax deprecations off. * Ensure that all lowering depwarns with existing line number information get this passed through as accessible metadata rather than as a string. * Use distinct functions for depwarns coming from the parser vs lowering, as these get line number information in a different way. TODO: * Figure out a decent `id` for the syntax and lowering depwarn messages * Make without_syntax_deprecations filter only depwarn messages, rather than everything!

* Additional exports * Fallback error message formatting * Minor global logger init min level bug

For now this seems like the right thing as error and informational reporting is a core requirement for a compiler - parts of the frontend and runtime now call the logging system when it's available.

These can be used to transform a lot of printf()'s into log statements.

This allows users to control whether a custom logger type will catch exceptions during message creation and log them, or simply allow them to pass through.

Provides a general tool to log information from the flisp frontend code. Make the syntax deprecations use this instead of using the purpose built syntax_depwarn function on the julia side. Also reinstate flisp-level awareness of the depwarn level. It's just simpler.

This is purely for implementation convenience. It restricts the levels artifically, but it's hard to imagine what anyone would do with more than a million custom levels.

This can be handled in a much nicer way by installing a logger in-process. TODO: Define such a logger and test it!

StefanKarpinski · 2017-11-03T23:17:53Z

Should we get some review on this?

c42f · 2017-11-04T00:29:57Z

Some high level feedback would be great. Particularly around how the system supports the various logging needs of base.

Just don't be too disturbed if there's a few details which are still broken here - it's definitely still a WIP, and I plan to pull it apart into several pieces for detailed review.

Port from MicroLogging refactoring Also rearrange exports to avoid exporting AbstractLogger-related methods.

ViralBShah · 2017-11-05T06:29:12Z

cc @tanmaykm

c42f · 2017-11-07T12:04:08Z

Ok, I've pulled out what I think is a mostly coherent subset of these changes into #24490 . This WIP is still useful for the moment as context for the larger ongoing work.

c42f · 2018-01-05T15:45:46Z

This is superseded now by #24490 and various follow on work.

ggggggggg reviewed Sep 14, 2017

View reviewed changes

c42f force-pushed the logging branch from 7cc9eda to aaddd03 Compare September 17, 2017 01:47

c42f mentioned this pull request Sep 17, 2017

[WIP] Flexible and convenient logging JuliaLang/Juleps#30

Merged

c42f force-pushed the logging branch 2 times, most recently from 6ddb8ce to ba866dc Compare September 30, 2017 02:36

c42f mentioned this pull request Oct 3, 2017

World age assertion adding backedges #23981

Closed

c42f force-pushed the logging branch 2 times, most recently from ed55d32 to 89c418f Compare October 22, 2017 20:51

helgee reviewed Oct 24, 2017

View reviewed changes

c42f added 12 commits October 26, 2017 06:16

Copy of MicroLogging source (656f937) exports + sysimg

283eb49

Some minor edits here to make things suitable for Base.

More backend interface renaming

99e682c

Use handle_message rather than dispatch_message, as not all message handling is pure dispatch (the message may be stored rather than sent elsewhere). Reuse the name dispatch_message internally.

Convert Pkg to use new Logging

9b7c697

Migrate loading to new logging infrastructure

d81e6d0

Convert libgit2 to use new logging

0bd2397

Changes ported from MicroLogging

0e52ef1

* Additional exports * Fallback error message formatting * Minor global logger init min level bug

Quote depwarns code expressions with backticks

e7798ee

libgit2 logging - minor fixes and updates

e062426

Pkg logging - exception and markdown fixes

40f8697

Remove sprintf dependency - use hex() and string() instead.

9fd7e73

pfitzseb mentioned this pull request Oct 29, 2017

Progress monitoring fallback to the console JunoLab/Juno.jl#29

Closed

c42f added 6 commits October 30, 2017 22:39

Upstream changes: docs + keyword splatting

7bdf93c

Move core Logging components into Base

d0f143a

For now this seems like the right thing as error and informational reporting is a core requirement for a compiler - parts of the frontend and runtime now call the logging system when it's available.

Tweak loading for core Logging in Base

544c6b9

Tweak depwarns for core Logging in Base

b674a36

Logging tools for use in the runtime C code

be777bc

These can be used to transform a lot of printf()'s into log statements.

Add catch_exceptions(::AbstractLogger)

7ed4de5

This allows users to control whether a custom logger type will catch exceptions during message creation and log them, or simply allow them to pass through.

c42f added 4 commits November 2, 2017 12:50

Deprecate --depwarn=error - use a custom logger instead

757c92c

Add module argument to jl_log() and jl_logf()

58fb9e7

Change log level limits to fit well within a flisp fixnum

a127e3f

This is purely for implementation convenience. It restricts the levels artifically, but it's hard to imagine what anyone would do with more than a million custom levels.

c42f force-pushed the logging branch from a86775d to a127e3f Compare November 2, 2017 05:26

c42f added 2 commits November 2, 2017 16:44

Remove all uses of --depwarn=error

ee8bb6e

This can be handled in a much nicer way by installing a logger in-process. TODO: Define such a logger and test it!

Cleanup: Extend Base methods with explicit Base prefix

483c771

c42f added 2 commits November 4, 2017 13:59

Rearrange logging source into a more logical order

bd6a3ae

Port from MicroLogging refactoring Also rearrange exports to avoid exporting AbstractLogger-related methods.

Port more MicroLogging changes - remove log config from core

8319628

c42f force-pushed the logging branch from e04066c to 8319628 Compare November 5, 2017 06:24

c42f mentioned this pull request Nov 6, 2017

RFC: Base logging #24490

Merged

6 tasks

c42f mentioned this pull request Dec 15, 2017

Base logging todo #25109

Closed

15 tasks

c42f closed this Jan 5, 2018

c42f added the logging The logging framework label Jan 5, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[WIP] More flexible and convenient logging #23712

[WIP] More flexible and convenient logging #23712

c42f commented Sep 14, 2017 •

edited

Loading

ggggggggg Sep 14, 2017

c42f Sep 14, 2017

ggggggggg Sep 15, 2017

c42f Sep 15, 2017

ggggggggg Sep 14, 2017

c42f Sep 14, 2017

ggggggggg Sep 15, 2017

c42f commented Sep 24, 2017 •

edited

Loading

helgee Oct 24, 2017 •

edited

Loading

pkofod Oct 24, 2017

c42f Oct 24, 2017

StefanKarpinski commented Nov 3, 2017

c42f commented Nov 4, 2017

ViralBShah commented Nov 5, 2017

c42f commented Nov 7, 2017

c42f commented Jan 5, 2018

		const _min_enabled_level = Ref(Debug)


		# A concretely typed cache of data extracted from the logger, plus the logger

[WIP] More flexible and convenient logging #23712

[WIP] More flexible and convenient logging #23712

Conversation

c42f commented Sep 14, 2017 • 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

c42f commented Sep 24, 2017 • edited Loading

helgee Oct 24, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

StefanKarpinski commented Nov 3, 2017

c42f commented Nov 4, 2017

ViralBShah commented Nov 5, 2017

c42f commented Nov 7, 2017

c42f commented Jan 5, 2018

c42f commented Sep 14, 2017 •

edited

Loading

c42f commented Sep 24, 2017 •

edited

Loading

helgee Oct 24, 2017 •

edited

Loading