Comments (6)
I'm aware of this problem under a bit of a different angle, something like "(log:info (call-that-uses-logging-itself))" hangs trying to take appender lock recursively.
I was planning to solve it, by making a change from "binary logging idea" issue, which would first compute all format arguments putting them into dynamic-extent vector, and then do the call.
That would solve the above problem, but not your example.
I think ideally it should behave as same as if the lock was not there (is like in single threaded built), which is same as recursive lock.
Imho the debug-log-statements is an overkill. Current behavior is obviously broken, recursive lock makes it behave same as it there was no lock, which satisfies principle of least surprise.
So unless you have objections, I'll just make recursive lock change (may have to wait until weekend) or I'll merge pull request for she same
Jan Moringen [email protected] wrote:
Consider the following:
(with-simple-restart (abort "Abort") (handler-bind ((error (lambda (condition) (log:error "caught error: ~A" condition) (abort)))) (log:info "~A") :finished))
(log:info "~A") is obviously wrong since there are not enough format arguments. One would expect this error to be caught and reported by the outer "catch-all" handler-bind. However, since the format error is signaled while in appender-do-append, the (log:error "caught error: ~A" condition) code re-enters appender-do-append and causes a recursive lock attempt. As a consequence, a relatively harmless format error in logging code escalates even beyond the intended "catch-all" error handling.
I can imagine two possible improvements:
Catch errors of his kind in log4cl and print a log message like [20:08:12] cl-user () - <>. This approach would similar to the usual <SOME-CLASS <> >-behavior. This solution would not change the control flow, i.e. return :finished in the above example, since no error would be signaled.
Use a recursive lock. In the above example this would lead to the output (in SBCL):
[20:08:12] cl-user () - caught error: error in FORMAT: required argument missing ~A ^
This solution would change the control flow since the format-error would still be signaled.
Make one of the two behaviors selectable as a configuration option or via a special variable debug-log-statements? :)
—
Reply to this email directly or view it on GitHub.
from log4cl.
I'm aware of this problem under a bit of a different angle, something like "(log:info (call-that-uses-logging-itself))" hangs trying to take appender lock recursively.
Out of curiosity: on which implementation does this happen? At least in SBCL, attempting to re-acquire a non-recursive lock signals an error instead of hanging.
I was planning to solve it, by making a change from "binary logging idea" issue, which would first compute all format arguments putting them into dynamic-extent vector, and then do the call.
That would solve the above problem, but not your example.
I think computing an intermediate value such as the formatted string outside the critical section and then writing it to the stream in the critical section would solve both problems. I wrote "intermediate value" because it may not be a formatted string for some kinds of appenders. This would also minimize the time spent in the critical section.
I think ideally it should behave as same as if the lock was not there (is like in single threaded built), which is same as recursive lock.
Imho the debug-log-statements is an overkill. Current behavior is obviously broken, recursive lock makes it behave same as it there was no lock, which satisfies principle of least surprise.
So unless you have objections, I'll just make recursive lock change (may have to wait until weekend) or I'll merge pull request for she same
The solution in the previous paragraph seems better to me although it requires more effort to implement.
Btw: I would really appreciate the binary logging idea for writing custom appenders.
from log4cl.
You are right about recursive lock on SBCL, gives an error instead of hanging now, maybe my memory is from other implementation?
I assume you mean using with-output-to-string
to save log statement into temp string? Reason its designed as is, is one of design goal was to minimize consing.
Right now even if you have a lot of debug/trace statements, and setting root level to debug, the consing impact is still low (when not using pretty printer), because everything gets printed directly to the eventual stream. Seems weird to give that up and introduce consing into design just to solve a concurrency issue.
What is the problem with recursive lock solution? I tested it and everything seems to work fine
(handler-bind ((error (lambda (e)
(log:error "Got error" e)
(abort))))
(log:info "~d")
(log:info "After the error"))
;
; caught WARNING:
; Too few arguments (0) to FORMAT "~d": requires at least 1.
; See also:
; The ANSI Standard, Section 22.3.10.2
;
; compilation unit finished
; caught 1 WARNING condition
<ERROR> [08:03:42] [repl-thread] cl-user () -
Got error E: #<SB-FORMAT:FORMAT-ERROR {100E149383}>
; Evaluation aborted on #<SB-INT:FORMAT-TOO-FEW-ARGS-WARNING "Too few arguments (~D) to ~S ~S: requires at least ~D." {100DF7E613}>.
from log4cl.
I assume you mean using
with-output-to-string
to save log statement into temp string?
Yes, at least for string-stream based appenders.
Right now even if you have a lot of debug/trace statements, and setting root level to debug, the consing impact is still low (when not using pretty printer), because everything gets printed directly to the eventual stream. Seems weird to give that up and introduce consing into design just to solve a concurrency issue.
I see. My point was that running formatter code in the critical section may block other threads longer than just writing a precomputed value to the stream. However, as you pointed out, formatting directly to the target stream avoids consing.
What is the problem with recursive lock solution?
I don't think there is any functional problem; the tradeoff is wrt. performance: less consing vs. smaller critical section. I'm not sure which one is more important.
Apart from that, it would be cool if one could write appenders that just receive the "raw" logging data without formatters being involved.
from log4cl.
The "able to write appenders without formatting being involved" is exactly what binary logging wish list issue is about, it would introduce new type of appender that receives a vector of values being logged, to do with as it wishes, from maintaining of circular buffet of last 1000 debug messages to cl-storing it to binary log file, for future analysis with some tool
Jan Moringen [email protected] wrote:
I assume you mean using with-output-to-string to save log statement into temp string?
Yes, at least for string-stream based appenders.
Right now even if you have a lot of debug/trace statements, and setting root level to debug, the consing impact is still low (when not using pretty printer), because everything gets printed directly to the eventual stream. Seems weird to give that up and introduce consing into design just to solve a concurrency issue.
I see. My point was that running formatter code in the critical section may block other threads longer than just writing a precomputed value to the stream. However, as you pointed out, formatting directly to the target stream avoids consing.
What is the problem with recursive lock solution?
I don't think there is any functional problem; the tradeoff is wrt. performance: less consing vs. smaller critical section. I'm not sure which one is more important.
Apart from that, it would be cool if one could write appenders that just receive the "raw" logging data without formatters being involved.
—
Reply to this email directly or view it on GitHub.
from log4cl.
Has been addressed in sharplispers#8.
from log4cl.
Related Issues (20)
- Log4Slime Elisp side fails to detect numeric EQL specializer
- public API changed: log:config :daily doesn't accept a pathname anymore, only strings HOT 2
- Log4slime Error Upon Startup (org-compatible-face) HOT 5
- log expansion should not capture stream HOT 2
- Log levels of parent loggers are not applied to messages of children. HOT 3
- Add syntax sugar for logging macros to drop innermost level of auto-naming
- slime error message when loading log4cl HOT 1
- log4cl not detecting existing package name
- dependency on sb-posix is not declared HOT 2
- problem on ABCL HOT 2
- Consider using Conium rather than SWANK-BACKEND
- Troubles with log4slime HOT 2
- log4cl:project-options doesn't work. HOT 1
- Unable to install `Log4Slime`
- I haven't thanked you enough. HOT 1
- JOIN-THREAD-ERROR HOT 3
- Recursive lock attempt with `log4cl`
- PLEASE REPORT BUGS IN MAINTAINED FORK https://github.com/sharplispers/log4cl
- Sly integration HOT 1
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from log4cl.