Commit Graph

78 Commits

Author SHA1 Message Date
Rusty Russell a06fa7f267 log: print UNUSUAL messages before log initialization too.
Otherwise we don't print out the upgrading messages when we move things!

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-11-23 22:42:34 +00:00
Rusty Russell b210c9d91f lightningd: use a simple array for less memory usage.
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>
2019-11-18 04:50:22 +00:00
Rusty Russell 39d537b495 lightningd: remove log_add functions.
They added complexity, and were only used in a few places.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-11-18 04:50:22 +00:00
Rusty Russell a83fd16840 lightningd: perform better log pruning.
1. Don't prune the last 10%.
2. Be more aggressive on pruning IO and DEBUG.
3. Account for skipped entries correctly across multiple prunes.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-11-18 04:50:22 +00:00
Rusty Russell 0c6d8996fc lightningd: avoid keeping multiple copies of nodeid.
Simple refcount FTW.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-11-18 04:50:22 +00:00
Rusty Russell 0607f998d1 options: allow --log-level <level>:<prefix> for finegrained log control.
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.
2019-11-18 04:50:22 +00:00
Rusty Russell ef7a820ab1 log: make formatting more consistent.
1. Printed form is always "[<nodeid>-]<prefix>: <string>"
2. "jcon fd %i" becomes "jsonrpc #%i".
3. "jsonrpc" log is only used once, and is removed.
4. "database" log prefix is use for db accesses.
5. "lightningd(%i)" becomes simply "lightningd" without the pid.
6. The "lightningd_" prefix is stripped from subd log prefixes, and pid removed.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
Changelog-changed: Logging: formatting made uniform: [NODEID-]SUBSYSTEM: MESSAGE
Changelog-removed: `lightning_` prefixes removed from subdaemon names, including in listpeers `owner` field.
2019-11-18 04:50:22 +00:00
Rusty Russell 86fb54a33b lightningd: remove per-peer log book.
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>
2019-11-18 04:50:22 +00:00
Rusty Russell 3270e5c843 lightningd: move log structs into log.c.
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>
2019-11-18 04:50:22 +00:00
Rusty Russell e433d4ddc1 lightningd: have logging include an optional node_id for each entry.
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>
2019-11-18 04:50:22 +00:00
Rusty Russell fe17acf07b TAGS: reformat to fix when PRINTF_FMT() used.
I was wondering why TAGS was missing some functions, and finally
tracked it down: PRINTF_FMT() confuses etags if it's at the start
of a function, and it ignores the rest of the file.

So we put PRINTF_FMT at the end, but that doesn't work for
*definitions*, only *declarations*.  So we remove it from definitions
and add gratuitous declarations in the few static places.1

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-11-01 17:27:20 -05:00
Rusty Russell e78a80495b log: make --log-file an early arg (since we move to dir early now).
Otherwise we bleed plugin log messages to stderr, as they're initted before
log-file.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-08-05 17:09:57 +08:00
Rusty Russell 5f02294b5b lightningd/log: prefix log messages with level.
In particular, this lets us spot UNUSUAL and BROKEN messages easily.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-07-02 03:26:10 +00:00
Rusty Russell bb7bbd03c5 lightningd: have json_stream_success start the "result" object.
"result" should always be an object (so that we can add new fields),
so make that implicit in json_stream_success.

This makes our primitives well-formed: we previously used NULL as our
fieldname when calling the first json_object_start, which is a hack
since we're actually in an object and the fieldname is 'result' (which
was already written by json_object_start).

There were only two cases which didn't do this:
1. dev-memdump returned an array.  No API guarantees on this.
2. shutdown returned a string.

I temporarily made shutdown return an empty object, which shouldn't
break anything, but I want to fix that later anyway.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2019-06-12 02:00:15 +00:00
trueptolemy 96135dab5e log: add 'warning' notification when log
- 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.
2019-06-07 01:23:51 +00:00
trueptolemy 231703cc7f plugin: Add new notification type: warning
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;
2019-06-07 01:23:51 +00:00
darosior 323adb467a jsonrpc: Add a category field to commands.
A new string field is added to the command structure and is specified at the creation of each native command, and in the JSON created by 'json_add_help_command()'.
2019-06-03 00:02:25 +00:00
Simon Vrouwe db57d9c5d2 lightningd: suppress IO_OUT logging for getlog command
Before this, the response of `getlog io` blew up quickly
when called multiple times.
2019-05-26 23:53:20 +00:00
Rusty Russell 87cd628f52 log: truncate giant IO logging.
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>
2019-04-08 04:41:43 +00:00
Michael Schmoock 4986d6b39d feat: block of newlines when attaching a logfile
This will make the logger write 4 newlines to re-attached logfiles.
The newlines wont appear on logfiles that are just created.
Additionally the server prints 50 '-' dashes before printing his
startup message, which also help increase readability on logfile.

This was inspired by the way Bitcoin Core handles logfiles.
2019-02-22 03:01:37 +00:00
Rusty Russell 68bb36b210 json-rpc: make commands return 'struct command_result *'.
Usually, this means they return 'command_param_failed()' if param()
fails, and changing 'command_success(); return;' to 'return
command_success()'.

Occasionally, it's more complex: there's a command_its_complicated()
for the case where we can't exactly determine what the status is,
but it should be considered a last resort.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-12-20 03:22:32 +00:00
Rusty Russell bc41ab2cb9 param: make json_tok_ handlers all return command_result, rename to param_
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>
2018-12-20 03:22:32 +00:00
Rusty Russell 12731c4a60 json_tok_len, json_tok_contents: rename to json_tok_full_len and json_tok_full
These are only supposed to be used when you want the token contents including
surrounding "".  We should use this when reporting errors, but usually
we just want to access the tok members directly.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-12-20 03:22:32 +00:00
Rusty Russell c4ffec57b4 log: play back prior log entries when opening log.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-12-18 12:16:14 +01:00
Rusty Russell a3a5ba5f21 options: set log-level and log-prefix early.
Otherwise we potentially miss debug-level logs.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-12-18 12:16:14 +01:00
Rusty Russell d7e233e47d Move json and param core functionality into common, for plugins.
json_escaped.[ch], param.[ch] and jsonrpc_errors.h move from lightningd/
to common/.  Tests moved too.

We add a new 'common/json_tok.[ch]' for the common parameter parsing
routines which a plugin might want, taking them out of
lightningd/json.c (which now only contains the lightningd-specific
ones).

The rest is mainly fixing up includes.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-12-10 00:00:50 +00:00
Rusty Russell 8015e7dcfb jsonrpc: add the obj token to the callback.
This (will) avoid the plugin having to walk back from the params object
as it currently does.

No code changes; I removed UNUSED and UNNEEDED labels from the other
parameters though (as *every* json_rpc callback needs to call param()
these days, they're *always* used).

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-12-10 00:00:50 +00:00
Rusty Russell 0dcd66880c Rename `struct json_result` to `struct json_stream` (RENAMEONLY)
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-10-19 22:02:11 +00:00
Rusty Russell e46ce0fc84 jsonrpc: declare up front whether a response is success or fail.
Such an API is required for when we stream it directly.  Almost all our
handlers fit this pattern already, or nearly do.

We remove new_json_result() in favor of explicit json_stream_success()
and json_stream_fail(), but still allowing command_fail() if you just
want a simple all-in-one fail wrapper.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-10-19 22:02:11 +00:00
arowser 3372228cad add "io" to -log-level usage 2018-09-14 22:12:13 +02:00
Christian Decker 8f56d64a1f log: Append the current time to the crash log filename
This should make it easier to identify the latest crash file and correlate
crashes with external monitoring tools.
2018-08-23 12:51:08 +02:00
Rusty Russell 00696277d2 logging: always dump a crash log, but make files per-pid.
Someone had a 21GB crash.log, which doesn't help anyone!

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-08-23 12:51:08 +02:00
Rusty Russell 213be90e77 log: implement reopening log-file on SIGHUP
Closes: #1623
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-08-23 12:51:08 +02:00
Mark Beckwith a3178b8177 param: remove old callback code
Cleaned up remaining code. Reduced comment noise. Reverted
macro names back to the original.

Signed-off-by: Mark Beckwith <wythe@intrig.com>
2018-08-20 01:02:25 +00:00
Mark Beckwith fa55e2cab0 param: upgraded json_tok_loglevel
Signed-off-by: Mark Beckwith <wythe@intrig.com>
2018-08-20 01:02:25 +00:00
practicalswift 9d9a9523d0 Use snprintf(...) instead of sprintf(...) 2018-08-02 16:14:21 +09:30
Rusty Russell 5cf34d6618 Remove tal_len, use tal_count() or tal_bytelen().
tal_count() is used where there's a type, even if it's char or u8, and
tal_bytelen() is going to replace tal_len() for clarity: it's only needed
where a pointer is void.

We shim tal_bytelen() for now.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-07-30 11:31:17 +02:00
Rusty Russell eae9b81099 json: json_add_hex_talarr for common case of dumping a tal object in hex.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-07-30 11:31:17 +02:00
Rusty Russell 9e14d6cf04 Remove all JSON commands and fields deprecated before 0.6.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-07-29 16:22:01 +02:00
Mark Beckwith f850849486 Modern param style for all remaining files
Removed `json_get_params`.

Also added json_tok_percent and json_tok_newaddr. Probably should
have been a separate PR but it was so easy.

[ Squashed comment update for gcc workaround --RR ]
Signed-off-by: Mark Beckwith <wythe@intrig.com>
2018-07-20 01:14:02 +00:00
Mark Beckwith 7f437715d5 Added error code parameter to command_fail
Until now, `command_fail()` reported an error code of -1 for all uses.
This PR adds an `int code` parameter to `command_fail()`, requiring the
caller to explicitly include the error code.

This is part of #1464.

The majority of the calls are used during parameter validation and
their error code is now JSONRPC2_INVALID_PARAMS.

The rest of the calls report an error code of LIGHTNINGD, which I defined to
-1 in `jsonrpc_errors.h`.  The intention here is that as we improve our error
reporting, all occurenaces of LIGHTNINGD will go away and we can eventually
remove it.

I also converted calls to `command_fail_detailed()` that took a `NULL` `data`
parameter to use the new `command_fail()`.

The only difference from an end user perspecive is that bad input errors that
used to be -1 will now be -32602 (JSONRPC2_INVALID_PARAMS).
2018-05-26 12:17:36 +02:00
nicolas.dorier d9eba0e924 Do not call strlen for every character in the log entry 2018-05-22 06:17:13 +02:00
Rusty Russell 1a4a59d221 common/daemon: common routines for all daemons.
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>
2018-04-03 14:03:28 +02:00
practicalswift 94ca824cf5 Use correct format strings for signed integers 2018-03-26 01:20:22 +00:00
conanoc e7c8b95be3 Fix include order 2018-03-26 00:30:39 +00:00
conanoc c4700a13a7 Add guard for BACKTRACE_SUPPORTED 2018-03-26 00:30:39 +00:00
practicalswift 98f49c0837 Remove include in file foo.c that is already included in foo.h 2018-03-25 23:54:21 +00:00
Rusty Russell de5d84097e lightningd: remove ltmp context now we have tmpctx.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
2018-03-16 00:16:10 +00:00
John Barboza b4f7ce61b4 Append to crash log instead of creating new one
Multiple crashes accumulate in case you have some kind
of auto-restart for daemons.
2018-03-11 14:30:34 +01:00
practicalswift d873bf60bf Remove unused parameter fieldname in json_add_log(..., const char *fieldname, ...) 2018-02-22 10:46:30 +01:00