This way we now always have the events date which were really missing,
especially when used with traces :
<0>2019-09-26T07:57:25.183845 [00|h2|1|mux_h2.c:3024] receiving H2 HEADERS frame : h2c=0x1ddcad0(B,FRP) h2s=0x1dde9e0(3,HCL)
<0>2019-09-26T07:57:25.183845 [00|h2|4|mux_h2.c:2505] h2c_bck_handle_headers(): entering : h2c=0x1ddcad0(B,FRP) h2s=0x1dde9>
<0>2019-09-26T07:57:25.183846 [00|h2|4|mux_h2.c:4096] h2c_decode_headers(): entering : h2c=0x1ddcad0(B,FRP)
<0>2019-09-26T07:57:25.183847 [00|h2|4|mux_h2.c:4298] h2c_decode_headers(): leaving : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183848 [00|h2|0|mux_h2.c:2559] rcvd H2 response : h2c=0x1ddcad0(B,FRH) : [3] H2 RES: HTTP/2.0 200
<0>2019-09-26T07:57:25.183849 [00|h2|4|mux_h2.c:2560] h2c_bck_handle_headers(): leaving : h2c=0x1ddcad0(B,FRH) h2s=0x1dde9e>
<0>2019-09-26T07:57:25.183849 [00|h2|4|mux_h2.c:2866] h2_process_demux(): no more Rx data : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183849 [00|h2|4|mux_h2.c:3123] h2_process_demux(): notifying stream before switching SID : h2c=0x1dd>
<0>2019-09-26T07:57:25.183850 [00|h2|4|mux_h2.c:1014] h2s_notify_recv(): in : h2c=0x1ddcad0(B,FRH) h2s=0x1dde9e0(3,HCL)
<0>2019-09-26T07:57:25.183850 [00|h2|4|mux_h2.c:3135] h2_process_demux(): leaving : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183851 [00|h2|4|mux_h2.c:3319] h2_send(): entering : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183851 [00|h2|4|mux_h2.c:3145] h2_process_mux(): entering : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183851 [00|h2|4|mux_h2.c:3234] h2_process_mux(): leaving : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183852 [00|h2|4|mux_h2.c:3428] h2_send(): leaving with everything sent : h2c=0x1ddcad0(B,FRH)
<0>2019-09-26T07:57:25.183852 [00|h2|4|mux_h2.c:3319] h2_send(): entering : h2c=0x1ddcad0(B,FRH)
It looks like some format options could finally be separate from the sink,
or maybe enforced. For example we could imagine making the date optional
or its resolution configurable within a same buffer.
Similarly, maybe trace events would like to always emit the date even
on stdout, while traffic logs would prefer not to emit the date in the
ring buffer given that there's already one in the message.
Logs and sinks were resorting to dirty hacks to initialize an FD to
non-blocking mode. Now we have a bit for this in the fd tab so we can
do it on the fly on first use of the file descriptor. Previously it was
set per log server by writing value 1 to the port, or during a sink
initialization regardless of the usage of the fd.
Now it is possible for a reader to subscribe and wait for new events
sent to a ring buffer. When new events are written to a ring buffer,
the applets that are subscribed are woken up to display new events.
For now we only support this with the CLI applet called by "show events"
since the I/O handler is indeed a CLI I/O handler. But it's not
complicated to add other mechanisms to consume events and forward them
to external log servers for example. The wait mode is enabled by adding
"-w" after "show events <sink>". An extra "-n" was added to directly
seek to new events only.
The principle is that when emitting a message, if some dropped events
were logged, we first attempt to report this counter before going
further. This is done under an exclusive lock while all logs are
produced under a shared lock. This ensures that the dropped line is
accurately reported and doesn't accidently arrive after a later
event.
The new "show events" CLI keyword lists supported event sinks. When
passed a buffer-type sink it completely dumps it.
no drops at all during attachment even at 8 millon evts/s.
still missing the attachment limit though.
This now provides sink_new_buf() which allocates a ring buffer. One such
ring ("buf0") of 1 MB is created already, and may be used by sink_write().
The sink's creation should probably be moved somewhere else later.
Let's not mess up with fd-specific code, locking nor message formating
here, and use the new generic function instead. This substantially
simplifies the sink_write() code and makes it more agnostic to the
output representation and storage.
This is the most basic type of sink. It pre-registers "stdout" and
"stderr", and is able to use writev() on them. The writev() operation
is locked to avoid mixing outputs. It's likely that the registration
should move somewhere else to take into account the fact that stdout
and stderr are still opened or are closed.
The principle will be to be able to dispatch events to various destinations
called "sinks". This is already done in part in logs where log servers can
be either a UDP socket or a file descriptor. This will be needed with the
new trace subsystem where we may also want to add ring buffers. And it turns
out that all such destinations make sense at all places. Logs may need to be
sent to a TCP server via a ring buffer, or consulted from the CLI. Trace
events may need to be sent to stdout/stderr as well as to remote log servers.
This patch creates a new structure "sink" aiming at addressing these similar
needs. The goal is to merge together what is common to all of them, such as
the output format, the dropped events count, etc, and also keep separately
the target identification (network address, file descriptor). Provisions
were made to have a "waiter" on the sink. For a TCP log server it will be
the task to wake up after writing to the log buffer. For a ring buffer, it
could be the list of watchers on the CLI running a "tail" operation and
waiting for new events. A lock was also placed in the struct since many
operations will require some locking, including the FD ones. The output
formats covers those in use by logs and two extra ones prepending the ISO
time in front of the message (convenient for stdio/buffer).
For now only the generic infrastructure is present, no type-specific
output is implemented. There's the sink_write() function which prepares
and formats a message to be sent, trying hard to avoid copies and only
using pointer manipulation, where the type-specific code just has to be
added. Dropped messages are already counted (for now 100% drop). The
message is put into an iovec array as it will be trivial to use with
file descriptors and sockets.
