On Tue, Apr 24, 2018 at 11:01 PM, Sage Weil <sage@xxxxxxxxxxxx> wrote:
> On Tue, 24 Apr 2018, kefu chai wrote:
>> hi,
>>
>> i am thinking about logging in the osd in seastar (BTW, how about
>> naming it oyster? =). in seastar, we print log[1] like
>>
>> seastar::logger logger{"osd"};
>> // ...
>> logger.info("i am doing fine.");
>> logger.error("something goes wrong: {}", std::current_exception());
>>
>> and the logger will print the above messages to either stdout and/or
>> syslog, depending on the configurations, like:
>>
>> INFO %Y-%m-%d %T,%03d [shard 0] osd - i am doing fine.
>> ERROR %Y-%m-%d %T,%03d [shard 0] osd - something goes wrong: std::bad_alloc
>>
>> so, in comparison with the logging in Ceph, the logging in seastar
>>
>> - resembles the logging module in python or printf()
>> - does not support fine-grained loglevel, it offers 5 log levels.
>
> This is probably better, honestly :)
>
>> - offers APIs to adjust the log level of a certain logger. like
>> global_logger_registry().set_logger_level("osd", log_level::debug);
>> - could be slower as the writing to stdout or syslog pipe could be a
>> blocking write. as both of them are buffered write. if the write
>> buffer or the pipe is full, the reactor thread is blocked.
>
> I don't think this is a concern. I have a couple other questions, though:
>
> 1- Can we nicely redirect output to a log file?
i believe we can redirect std::cout to a log file using dup2().
>
> 2- Do the arguments get evaluated even if the logging level is low? That
no. see
=== 8< ====
template <typename... Args>
void log(log_level level, const char* fmt, Args&&... args) {
if (is_enabled(level)) {
try {
do_log(level, fmt, std::forward<Args>(args)...);
} catch (...) {
failed_to_log(std::current_exception());
}
}
}
=== >8 ===
> would be a major downside in comparison to the dout stuff. If so we
> should probably write a dout-like wrapper to accomplish the same thing?
>
> 3- The power (and downfall) of the dout() stuff is the ability to leverage
> the operator<<() helpers for random types and containers. Would we
> accomplish the same thing with something like
>
> logger.info("foo {}", stringify(foo));
>
> ?
actually, seastar logger will always insert the stringify parameter
whenever it finds a `{}` in the fmt string, and then move on to the
next parameter.
>
>> for taking the full advantage of seastar, i don't think we should
>> continue using the existing logging infrastructure, as it uses a grand
>> lock for protecting the log entry queue. and hence is not lock free,
>> and the logging thread will be competing with the seastar's reactor
>> thread.
>
> Agree! We do need to make it "work" though through a clever dout macro
> (or whatever) so that code like MonClient can still be used from a seastar
> osd.
>
>> we could support the streaming semantic used by ceph::logging, but we
>> will have to stringify all parameters even they will not be printed
>> according to current logging level setting. that'd be a serious
>> performance punishment. and neither seastar logging nor ceph::logging
>> prints the logging message to a string buffer in this case.
>>
>> i think a compromised approach would be using a compile-time switch to
>> define two implementations for "dout(lv)" for the code shared by osd
>> and non-seastarized parts of ceph. and we can use the same facility
>> (stdout or syslog) and the same prefix as seastar does in our seastar
>> implementation, so it would be easier to debug osd-in-seastar in
>> future.
>
> Yeah
>
>> or we could use tracelog() in LTTNG. but it uses the same style just
>> like seastar and it only allows parameters supported vasprintf(3). so
>> it's more limited than seaststar logging.
>
> If we're rewriting logging/tracepoints anyway, I think it is worth
> going all the way and outputting structured tracepoints. In that case,
> the only use of the logger would be ad hoc prints (like above) for
> developers and debugging only, in which case I don't think performance or
> logging granularity really matters much.
>
> That said, the icky part of the current lttng tracepoints is that every
> tracepoint has to be defined in two places: in the actual code, and also a
> prototype in the .tp file. Is there a way to make these a bit
> lighter-weight?
ahh, that would be surely a pain. i will take a closer look at it.
also, if we are going with the structured tracepoint, probably we will
need to figure out an intuitive way to print the the class/struct
instances. as tracelog only prints args of primitive types .
>
> sage
--
Regards
Kefu Chai
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
