The tal overhead of 5 pointers, the linked list node is 2; and we also
tal'd the string. That's 96 bytes per entry.
Use a simple array instead, though it means more work on deletion
since each log_entry is no longer a tal object.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This allows finegrained logging control of particular subdaemons or
subsystems.
To do this, we defer setting the logging levels for each log object
until after early argument parsing (since e.g. "bitcoind" log object
is created early).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-changed: Options: log-level can now specify different levels for different subsystems.
We had a separate logbook for each peer, and copy log entries above
the printable log level into the master logbook. This didn't always
work well, since we didn't dump it on crash for example.
Keep a single global logbook instead, and remove this infrastructure.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Simply better encapsulation. We still need to expose log_entry, since the
notification hook uses it though.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
A log can have a default node_id, which can be overridden on a per-entry
basis. This changes the format of logging, so some tests need rework.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
- Related Changes for `warning` notification
Add a `bool` type parameter in `log_()` and `lov()`, this `bool` flag
indicates if we should call `warning` notifier.
1) The process of copying `log_book` of every peer to the `log_book` of
`ld` is usually included in `log_()` and `lov()`, and it may lead to
repeated `warning` notification. So a `bool`, which explicitly indicates
if the `warning` notification is disabled during this call, is necessary
.
2) The `LOG_INFO` and `LOG_DEBUG` level don't need to call
warning, so set that `bool` paramater as `FALSE` for these log level and
only set it as `TRUE` for `LOG_UNUAUSL`/`LOG_BROKEN`. As for `LOG_IO`,
it use `log_io()` to log, so we needn't think about notifier for it.
This notification bases on `LOG_BROKEN` and `LOG_UNUSUAL` level log.
--Introduction
A notification for topic `warning` is sent every time a new `BROKEN`/
`UNUSUAL` level(in plugins, we use `error`/`warn`) log generated, which
means an unusual/borken thing happens, such as channel failed,
message resolving failed...
```json
{
"warning": {
"level": "warn",
"time": "1559743608.565342521",
"source": "lightningd(17652): 0821f80652fb840239df8dc99205792bba2e559a05469915804c08420230e23c7c chan #7854:",
"log": "Peer permanent failure in CHANNELD_NORMAL: lightning_channeld: sent ERROR bad reestablish dataloss msg"
}
}
```
1. `level` is `warn` or `error`:
`warn` means something seems bad happened and it's under control, but
we'd better check it;
`error` means something extremely bad is out of control, and it may lead
to crash;
2. `time` is the second since epoch;
3. `source`, in fact, is the `prefix` of the log_entry. It means where
the event happened, it may have the following forms:
`<node_id> chan #<db_id_of_channel>:`, `lightningd(<lightningd_pid>):`,
`plugin-<plugin_name>:`, `<daemon_name>(<daemon_pid>):`, `jsonrpc:`,
`jcon fd <error_fd_to_jsonrpc>:`, `plugin-manager`;
4. `log` is the context of the original log entry.
--Note:
1. The main code uses `UNUSUAL`/`BROKEN`, and plugin module uses `warn`
/`error`, considering the consistency with plugin, warning choose `warn`
/`error`. But users who use c-lightning with plugins may want to
`getlog` with specified level when receive warning. It's the duty for
plugin dev to turn `warn`/`error` into `UNUSUAL`/`BROKEN` and present it
to the users, or pass it directly to `getlog`;
2. About time, `json_log()` in `log` module uses the Relative Time, from
the time when `log_book` inited to the time when this event happend.
But I consider the `UNUSUAL`/`BROKEN` event is rare, and it is very
likely to happen after running for a long time, so for users, they will
pay more attention to Absolute Time.
-- Related Change
1. Remove the definitions of `log`, `log_book`, `log_entry` from `log.c`
to `log.h`, then they can be used in warning declaration and definition.
2. Remove `void json_add_time(struct json_stream *result, const char
*fieldname, struct timespec ts)` from `log.c` to `json.c`, and add
related declaration in `json.h`. Now the notification function in
`notification.c` can call it.
2. Add a pointer to `struct lightningd` in `struct log_book`. This may
affect the independence of the `log` module, but storing a pointer to
`ld` is more direct;
Adding a giant IO message simply causes it to be pruned immediately,
so truncate it if it's more than 1/64 the max size.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Handers of a specific form are both designed to be used as callbacks
for param(), and also dispose of the command if something goes wrong.
Make them return the 'struct command_result *' from command_failed(),
or NULL.
Renaming them just makes sense: json_tok_XXX is used for non-command-freeing
parsers too.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
In particular, the main daemon and subdaemons share the backtrace code,
with hooks for logging.
The daemon hook inserts the io_poll override, which means we no longer
need io_debug.[ch]. Though most daemons don't need it, they still link
against ccan/io, so it's harmess (suggested by @ZmnSCPxj).
This was tested manually to make sure we get backtraces still.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This means the caller needs to supply an explicit log to base the
subd log on, and also a callback for error handling.
The callback is kind of ugly, but it gets reworked towards the end
of this series.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
BackgroundL Each log has a log_book: many logs can share the same one,
as each one can have a separate prefix.
Testing tickled a bug at the end of this series, where subd was
logging to the peer's log_book on shutdown, but the peer was already
freed. We've already had issues with logging while lightningd is
shutting down.
There are times when reference counting really is the right answer,
this seems to be one of them: the 'struct log' share the 'struct
log_book' and the last 'struct log' cleans it up.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We currently don't handle LOG_IO properly, and we turn it into a string
before handing it to the ->print function, which makes it ugly for
the case where we're using copy_to_parent_log, and also means in
that case we lose *what peer* the IO is coming from.
Now, we handle the io as a separate arg, which is much neater.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
With the new 'human-readable' mode of lightning-cli, this actually produces
a valid config file. It's a bit hacky though...
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We use the tal notifiers to attach a `backtrace` object on every
allocation.
This also means moving backtrace_state from log.c into lightningd.c, so
we can hand it to memleak_init().
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
It crashes under valgrind, causing a valgrind error: valgrind gives us a
backtrace anyway, so we don't need it.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Some fields were redundant, some are simply moved into 'struct lightningd'.
All routines updated to hand 'struct lightningd *ld' now.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Also, we split the more sophisticated json_add helpers to avoid pulling in
everything into lightning-cli, and unify the routines to print struct
short_channel_id (it's ':', not '/' too).
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
To avoid everything pulling in HTLCs stuff to the opening daemon, we
split the channel and commit_tx routines into initial_channel and
initial_commit_tx (no HTLC support) and move full HTLC supporting versions
into channeld.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
We used level -1 to mean "append to log", but that doesn't actually
work, and results in an assert if we try to prune the logs:
lightningd: daemon/pseudorand.c:36: pseudorand: Assertion `max' failed.
Expose logv_add and use that.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Before we had a global secp256k1_ctx we needed to hold this to print
out pubkeys, now it's completely orthogonal.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
The most complex thing we've logged yet, so we extract the core of the
log_struct_ function to call it multiple times.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Uses a gcc extension (cast to union) for typechecking, but that can be
removed for compilers which don't support it.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Rusty Russell
trueptolemy
Mark Beckwith
practicalswift
Lucas Betschart