OPTIM: server: publish UP/DOWN events from STATE change
Reuse cb_data from STATE event to publish UP and DOWN events.
This saves some CPU time since the event is only constructed
once to publish STATE, STATE+UP or STATE+DOWN depending on the
state change.
SERVER_STATE is implemented as an advanced server event.
It is published each time the server's effective state changes.
(when s->cur_state changes)
SERVER_STATE data is an event_hdl_cb_data_server_state struct that
provides additional info related to the server state change, but can
be casted as a regular event_hdl_cb_data_server struct if additional
info is not needed.
add a macro helper to help publish server events to global and
per-server subscription list at once since all server events
support both subscription modes.
MEDIUM: stconn: Check room needed to unblock opposite SC when data was sent
After a sending attempt, we check the opposite SC to see if it is waiting
for a minimum free space to receive more data. If the condition is
respected, it is unblocked. 0 is special case where the SC is
unconditionally unblocked.
MEDIUM: stconn: Check room needed to unblock SC on fast-forward
During fast-forward, if the SC is waiting for a minimum free space to
receive more data and some data was sent, it is only unblock is the
condition is respected. 0 is special case where the SC is unconditionally
unblocked.
MEDIUM: applet: Check room needed to unblock opposite SC when data was consumed
If the opposite SC is waiting for a minimum free space to receive more data,
it is only unblock is the condition is respected. 0 is a special cases where
the opposite SC is always unblocked.
BUG/MEDIUM: stconn: Unblock SC from stream if there is enough room to progrees
At the end of process_stream(), in sc_update_rx(), the SC is now unblocked
if it was waiting for room and the free space in the input buffer is large
enough. This patch should fix an issue with the compression filter that can
leave the channel's buffer empty while the endpoint is waiting for room to
progress. Indeed, in this case, because the buffer is empty, there is no
send attempt and no other way to unblock the SE.
This commit depends on following commits:
* MEDIUM: tree-wide: Change sc API to specify required free space to progress
* MINOR: stconn: Add a field to specify the room needed by the SC to progress
* MINOR: peers: Use the applet API to send message
* MINOR: stats: Use the applet API to write data
* MINOR: cli: Use applet API to write output message
It should fix a regression introduced with the commit 341a5783b
("BUG/MEDIUM: stconn: stop to enable/disable reads from streams via
si_update_rx").
It must be backported iff the commit above is also backported. It was not
backported yet and it is thus probably a good idea to not do so to avoid to
backport too many change..
MEDIUM: tree-wide: Change sc API to specify required free space to progress
sc_need_room() now takes the required free space to receive more data as
parameter. All calls to this function are updated accordingly. For now, this
value is set but not used. When we are waiting for a buffer, 0 is used. So
we expect to be unblocked ASAP. However this must be reviewed because
SC_FL_NEED_BUF is probably enough in this case and this flag is already set
if the input buffer allocation fails.
MINOR: stconn: Add a field to specify the room needed by the SC to progress
When the SC is blocked because it is waiting for room in the input buffer,
it will be responsible to specify the minimum free space required to
progress. In this commit, we only introduce the field in the stconn
structure that will be used to store this value. It is a signed value with
the following meaning:
* -1: The SC is waiting for room but not based on the buffer state. It
will be typically used during splicing when the pipe is full. In
this case, only a successful send can unblock the SC.
* >= 0; The minimum free space in the input buffer to unblock the SC. 0 is
a special value to specify the SC must be unblocked ASAP, by the
stream, at the end of process_stream() or when output data are
consumed on the opposite side.
The peers applet now use the applet API to send message instead of the
channel API. This way, it does not need to take care to request more room if
it fails to put data into the channel's buffer.
stats_putchk() is updated to use the applet API instead of the channel API
to write data. To do so, the appctx is passed as parameter instead of the
channel. This way, the applet does not need to take care to request more
room it it fails to put data into the channel's buffer.
MINOR: cli: Use applet API to write output message
Instead of using the channel API to to write output message from the CLI
applet, we use the applet API. This way, the applet does not need to take
care to request more room it it fails to put its message into the channel's
buffer.
MINOR: ssl: allow to change the server signature algorithm
This patch introduces the "sigalgs" keyword for the bind line, which
allows to configure the list of server signature algorithms negociated
during the handshake. Also available as "ssl-default-bind-sigalgs" in
the default section.
Willy Tarreau [Thu, 4 May 2023 17:07:56 +0000 (19:07 +0200)]
MINOR: debug: make "show threads" properly iterate over all threads
Previously it would re-dump all threads to the same trash if the output
buffer was full, which it never was since the trash is of the same size.
Now it dumps one thread, copies it to the buffer and yields until it can
continue. Showing 256 threads works as expected.
Willy Tarreau [Thu, 4 May 2023 16:52:51 +0000 (18:52 +0200)]
MINOR: debug: write panic dump to stderr one thread at a time
Currently large setups cannot dump all their threads because they're
first dumped to the trash buffer, then copied to stderr. Here we can
now change this, instead we dump one thread at a time into the trash
and immediately send it to stderr. We also keep a copy into a local
trash chunk that's assigned to thread_dump_buffer so that a core file
still contains a copy of a large number of threads, which is generally
sufficient for the vast majority of situations.
It was verified that dumping 256 threads now produces ~55kB of output
and all of them are properly dumped.
Willy Tarreau [Thu, 4 May 2023 14:23:51 +0000 (16:23 +0200)]
MEDIUM: debug: simplify the thread dump mechanism
The thread dump mechanism that is used by "show threads" and by the
panic dump is overly complicated due to an initial misdesign. It
firsts wakes all threads, then serializes their dumps, then releases
them, while taking extreme care not to face colliding dumps. In fact
this is not what we need and it reached a limit where big machines
cannot dump all their threads anymore due to buffer size limitations.
What is needed instead is to be able to dump *one* thread, and to let
the requester iterate on all threads.
That's what this patch does. It adds the thread_dump_buffer to the
struct thread_ctx so that the requester offers the buffer to the
thread that is about to be dumped. This buffer also serves as a lock.
A thread at rest has a NULL, a valid pointer indicates the thread is
using it, and 0x1 (NULL+1) is used by the dumped thread to tell the
requester it's done. This makes sure that a given thread is dumped
once at a time. In addition to this, the calling thread decides
whether it accesses the thread by itself or via the debug signal
handler, in order to get a backtrace. This is much saner because the
calling thread is free to do whatever it wants with the buffer after
each thread is dumped, and there is no dependency between threads,
once they've dumped, they're free to continue (and possibly to dump
for another requester if needed). Finally, when the THREAD_DUMP
feature is disabled and the debug signal is not used, the requester
accesses the thread by itself like before.
For now we still have the buffer size limitation but it will be
addressed in future patches.
As such, NS_TO_TV usage in hlua_now() is currently incorrect and this
results in unexpected values being passed to lua.
In this patch, we're adding an extra parenthesis around 't' in NS_TO_TV()
macro to make it safe against such usages. (that is: ensure proper
argument expansion as if NS_TO_TV was implemented as a function)
BUG/MINOR: mux-h2: Also expect data when waiting for a tunnel establishment
When a client H2 stream is waiting for a tunnel establishment, it must state
it expects data from server. It is the second fix that should fix
regressions of the commit 2722c04b ("MEDIUM: mux-h2: Don't expect data from
server as long as request is unfinished")
Willy Tarreau [Thu, 4 May 2023 14:28:30 +0000 (16:28 +0200)]
BUG/MINOR: debug: do not emit empty lines in thread dumps
In 2.3, commit 471425f51 ("BUG/MINOR: debug: Don't dump the lua stack
if it is not initialized") introduced the possibility to emit an empty
line when there's no Lua info to dump. The problem is that doing this
on the CLI in "show threads" marks the end of the output, and it may
affect some external tools. We need to make sure that LFs are only
emitted if there's something on the line and that all lines properly
start with the prefix.
This may be backported as far as 2.0 since the commit above was
backported there.
MINOR: mux-quic: close connection asap on local error
With the change for QUIC MUX local error API, the new flag QC_CF_ERRL is
now checked on qc_detach(). If set, qcs instance is freed even though
transfer is not finished. This should help to quickly release qcs and
eventually all MUX instance resources.
To further accelerate this, a specific check has been added in
qc_shutw(). It is skipped if local error flag is set to prevent noisy
reset stream invocation. In the same way, QUIC MUX is not rescheduled on
qc_recv_buf() operation if local error flag set.
MINOR: mux-quic: report local error on stream endpoint asap
If an error a detected at the MUX layer, all remaining stream endpoints
should be closed asap with error set. This is now done by checking for
QC_CF_ERRL flag on qc_wake_some_streams() and qc_send_buf(). To complete
this, qc_wake_some_streams() is called by qc_process() if needed.
This should help to quickly release streams as soon as a new error is
detected locally by the MUX or APP layer. This allows to in turn free
the MUX instance itself. Previously, error would not have been
automatically reported until the transport layer closure would occur
on CONNECTION_CLOSE emission.
When a fatal error is detected by the QUIC MUX or H3 layer, the
connection should be closed with a CONNECTION_CLOSE with an error code
as the reason.
Previously, a direct call was used to the quic_conn layer to try to
close the connection. This API was adjusted to be more flexible. Now,
when an error is detected, the function qcc_set_error() is called. This
set the flag QC_CF_ERRL with the error code stored by the MUX. The
connection will be closed soon so most of the operations are not
conducted anymore. Connection is then finally closed during qc_send()
via quic_conn layer if QC_CF_ERRL is set. This will set the flag
QC_CF_ERRL_DONE which indicates that the MUX instance can be freed.
This model is cleaner and brings the following improvments :
- interaction with quic_conn layer for closure is centralized on a
single function
- CO_FL_ERROR is not set anymore. This was incorrect as this should be
reserved to errors reported by the transport layer to be similar with
other haproxy components. As a consequence, qcc_is_dead() has been
adjusted to check for QC_CF_ERRL_DONE to release the MUX instance.
MINOR: mux-quic: wake up after recv only if avail data
When HTX content is transferred from qcs instance to upper stream
endpoint, a wakeup is conducted for MUX tasklet. However, this is only
necessary if demux was interrupted due to a full QCS HTX buffer.
BUG/MINOR: mux-quic: prevent quic_conn error code to be overwritten
When MUX performs a graceful shutdown, quic_conn error code is set to a
"no error" code which depends on the application layer used. However,
this may overwrite a previous error code if quic_conn layer has detected
an error on its side.
In practice, this behavior has not been seen on production. In fact, it
may have undesirable effect only if this error code modification happens
between the quic_conn error detection and the emission of the
CONNECTION_CLOSE, so it should be pretty rare. However, there is still a
tiny possibility it may happen.
To prevent this, first check that quic_conn error code is not set before
setting it. Ideally, transport layer API should be adjusted to be able
to set this without fiddling with the quic_conn directly.
BUG/MEDIUM: mux-h2: Properly handle end of request to expect data from server
The commit 2722c04b ("MEDIUM: mux-h2: Don't expect data from server as long
as request is unfinished") introduced a regression in the H2 multiplexer.
The end of the request is not systematically handled to state a H2 stream on
client side now expexts data from the server.
Indeed, while the client is uploading its request, the H2 stream warns it
does not expect data from the server. This way, no server timeout is applied
at this stage. When end of the request is detected, the H2 stream must state
it now expects the server response. This enables the server timeout.
However, it was only performed at one place while the end of the request can
be handled at different places. First, during a zero-copy in
h2_rcv_buf(). Then, when the SC is created with the full request. Because of
this bug, it is possible to totally disable the server timeout for H2
streams.
In h2_rcv_buf(), we now rely on h2s flags to detect the end of the request,
but only when the rxbuf was emptied.
Willy Tarreau [Thu, 4 May 2023 09:50:26 +0000 (11:50 +0200)]
MINOR: debug: permit the "debug dev loop" to run under isolation
Sometimes it's convenient to test the effect of tasks running under
isolation, e.g. to validate the contents of the crash dumps. Let's
add an optional "isolated" keyword to "debug dev loop" for this.
Willy Tarreau [Thu, 4 May 2023 09:30:55 +0000 (11:30 +0200)]
BUG/MINOR: debug: fix incorrect profiling status reporting in show threads
Thread dumps include a field "prof" for each thread that reports whether
task profiling is currently active or not. It turns out that in 2.7-dev1,
commit 680ed5f28 ("MINOR: task: move profiling bit to per-thread")
mistakenly replaced it with a check for the current thread's bit in the
thread dumps, which basically is the only place where another thread is
being watched. The same mistake was done a few lines later by confusing
threads_want_rdv_mask with the profiling mask. This mask disappeared
in 2.7-dev2 with commit 598cf3f22 ("MAJOR: threads: change thread_isolate
to support inter-group synchronization"), though instead we know the ID
of the isolated thread. This commit fixes this and now reports "isolated"
instead of "wantrdv".
Willy Tarreau [Thu, 4 May 2023 06:09:02 +0000 (08:09 +0200)]
DEV: haring: automatically disable DEBUG_STRICT
Ideally haring should be compiled with the same options as haproxy so
that ring headers have the same size (e.g. with/without locks, with/
without lock debugging). But when enabling DEBUG_STRICT, BUG_ON() is
enabled and breaks the build by making references to complain() and
ha_backtrace_to_stderr().
Let's just disable DEBUG_STRICT before opening include files. This is
sufficient to address the problem.
This may be backorted to older versions that include haring.
Willy Tarreau [Wed, 3 May 2023 14:18:30 +0000 (16:18 +0200)]
MINOR: activity: allow "show activity" to restart in the middle of a line
16kB buffers are not enough to dump 4096 threads with up to 10 bytes value
on each line. By storing the column number in the applet's context, we can
now restart from the last attempted column. This requires to dump all values
as they are produced, but it doesn't cost that much: a 4096-thread output
from a fesh process produces 300kB of output in ~8ms, or ~400us per call
(19*16kB), most of which are spent in vfprintf(). Given that we don't print
more than needed, it doesn't really change anything.
The main caveat is that when interrupted on such large lines, there's a
great possibility that the total or average on the first column doesn't
match anymore the sum or average of all dumped values. In order to avoid
this whenever possible (typically less than ~1500 threads), we first try
to dump entire lines and only proceed one column at a time when we have
to retry a failed dump. This is already the same for other stats that are
dumped in an interruptible way anyway and there's little that can be done
about it at this point (and not much immediately perceived benefit in
doing this with extreme accuracy for >1500 threads).
Willy Tarreau [Wed, 3 May 2023 13:52:19 +0000 (15:52 +0200)]
MINOR: activity: allow "show activity" to restart dumping on any line
When using many threads, it's difficult to see the end of "show activity"
due to the numerous columns which fill the buffer. For example a dump of
a 256-thread, freshly booted process yields around 15kB.
Here by arranging the dump in a loop around a switch/case block where
each case checks the code line number against the current dump position,
we have a restartable counter for free with a granularity of the line of
code, without having to maintain a matching between states and specific
lines. It just requires to reset the trash buffer for each line and to
try to dump it after each line.
Now dumping 256 threads after a few seconds of traffic happily emits 20kB.
Willy Tarreau [Wed, 3 May 2023 13:25:04 +0000 (15:25 +0200)]
MINOR: activity: iterate over all fields in a main loop for dumping
Now each line of "show activity" will iterate over n+2 fields, one for
the line header, one for the total, and one per thread. This will soon
allow us to save the current state in a restartable way.
Willy Tarreau [Wed, 3 May 2023 09:22:45 +0000 (11:22 +0200)]
DEBUG: cli: add "debug dev task" to show/wake/expire/kill tasks and tasklets
When analyzing certain types of bugs in field, sometimes it would be
nice to be able to wake up a task or tasklet to see how events progress
(e.g. to detect a missing wakeup condition), or expire or kill such a
task. This restricted command shows hte current state of a task or tasklet
and allows to manipulate it like this. However it must be used with extreme
care because while it does verify that the pointers are mapped, it cannot
know if they point to a real task, and performing such actions on something
not a task will easily lead to a crash. In addition, performing a "kill"
on a task has great chances of provoking a deferred crash due to a double
free and/or another kill that is not idempotent. Use with extreme care!
Willy Tarreau [Wed, 3 May 2023 09:29:54 +0000 (11:29 +0200)]
BUG/MINOR: stream/cli: fix stream age calculation in "show sess"
The "show sess" command displays the stream's age in synthetic form,
and also makes it appear in the long version (show sess all). But that
last one uses the wrong origin, it uses accept_date.tv_sec instead of
accept_ts (formerly known as tv_accept). This was introduced in 1.4.2
with the long format, with commit 66dc20a17 ("[MINOR] stats socket: add
show sess <id> to dump details about a session"), while the code that
split the two variables was introduced in 1.3.16 with commit b7f694f20
("[MEDIUM] implement a monotonic internal clock"). This problem was
revealed by recent change ad5a5f677 ("MEDIUM: tree-wide: replace timeval
with nanoseconds in tv_accept and tv_request") that made this value report
random garbage, and generally emphasized by the fact that in 2.8 the two
clocks have sufficiently large an offset for such mistakes to be noticeable
early.
Arguably a difference between date and accept_date could also make sense,
to indicate if the stream had been there for more than 49 days, but this
would introduce instabilities for most sockets (including negative times)
for extremely rare cases while the goal is essentially to see how much
longer than a configured timeout a stream has been there. And that's what
other locations (including the short form) provide.
This patch could be backported but most users will never notice. In case
of backport, tv_accept.tv_sec should be used instead of accept_date.tv_sec.
MINOR: ssl: disable CRL checks with WolfSSL when no CRL file
WolfSSL is enabling by default the CRL checks even if a CRL file wasn't
provided. This patch resets the default X509_STORE flags so this is
not checked by default.
As this feature has a dependency on resolvers being configured,
this test acts as good documentation as well.
This change also has a spelling fix for filename.
Released version 2.8-dev9 with the following main changes :
- MINOR: quic: Move traces at proto level
- BUG/MINOR: quic: Possible memory leak from TX packets
- BUG/MINOR: quic: Possible leak during probing retransmissions
- BUG/MINOR: quic: Useless probing retransmission in draining or killing state
- BUG/MINOR: quic: Useless I/O handler task wakeups (draining, killing state)
- CLEANUP: quic: rename frame types with an explicit prefix
- CLEANUP: quic: rename frame variables
- CLEANUP: quic: Remove useless parameters passes to qc_purge_tx_buf()
- CLEANUP: quic: Rename <buf> variable to <token> in quic_generate_retry_token()
- CLEANUP: quic: Rename <buf> variable into quic_padding_check()
- CLEANUP: quic: Rename <buf> variable into quic_rx_pkt_parse()
- CLEANUP: quic: Rename <buf> variable for several low level functions
- CLEANUP: quic: Make qc_build_pkt() be more readable
- CLEANUP: quic: Rename quic_get_dgram_dcid() <buf> variable
- CLEANUP: quic: Rename several <buf> variables at low level
- CLEANUP: quic: Rename <buf> variable into quic_packet_read_long_header()
- CLEANUP: quic: Rename <buf> variable into qc_parse_hd_form()
- CLEANUP: quic: Rename several <buf> variables into quic_sock.c
- DEBUG: crash using an invalid opcode on x86/x86_64 instead of an invalid access
- DEBUG: crash using an invalid opcode on aarch64 instead of an invalid access
- DEV: h2: add a script "mkhdr" to build h2 frames from scratch
- DEV: h2: support reading frame payload from a file
- MINOR: acme.sh: add the deploy script for acme.sh in admin directory
- BUG/MEDIUM: mux-quic: do not emit RESET_STREAM for unknown length
- BUG/MEDIUM: mux-quic: improve streams fairness to prevent early timeout
- BUG/MINOR: quic: prevent buggy memcpy for empty STREAM
- MINOR: mux-quic: do not set buffer for empty STREAM frame
- MINOR: mux-quic: do not allocate Tx buf for empty STREAM frame
- MINOR: quic: finalize affinity change as soon as possible
- BUG/MINOR: quic: fix race on quic_conns list during affinity rebind
- CI: switch to Fastly CDN to download LibreSSL
- BUILD: ssl: switch LibreSSL to Fastly CDN
- BUG/MINOR: clock: fix a few occurrences of 'now' being used in place of 'date'
- BUG/MINOR: spoe: use "date" not "now" in debug messages
- BUG/MINOR: activity: show wall-clock date, not internal date in show activity
- BUG/MINOR: opentracing: use 'date' instead of 'now' in debug output
- Revert "BUG/MINOR: clock: fix a few occurrences of 'now' being used in place of 'date'"
- BUG/MINOR: calltrace: fix 'now' being used in place of 'date'
- BUG/MINOR: trace: show wall-clock date, not internal date in show activity
- BUG/MINOR: hlua: return wall-clock date, not internal date in core.now()
- BUG/MEDIUM: spoe: Don't start new applet if there are enough idle ones
- BUG/MINOR: stconn: Fix SC flags with same value
- BUG/MINOR: resolvers: Use sc_need_room() to wait more room when dumping stats
- BUG/MEDIUM: tcpcheck: Don't eval custom expect rule on an empty buffer
- BUG/MINOR: stats: report the correct start date in "show info"
- MINOR: time: add conversions to/from nanosecond timestamps
- MINOR: time: replace calls to tv_ms_elapsed() with a linear subtract
- MINOR: spoe: switch the timeval-based timestamps to nanosecond timestamps
- MEDIUM: tree-wide: replace timeval with nanoseconds in tv_accept and tv_request
- MINOR: stats: use nanoseconds, not timeval to compute uptime
- MINOR: activity: use nanoseconds, not timeval to compute uptime
- MINOR: checks: use a nanosecond counters instead of timeval for checks->start
- MINOR: clock: do not use now.tv_sec anymore
- MEDIUM: clock: replace timeval "now" with integer "now_ns"
- MINOR: clock: replace the timeval start_time with start_time_ns
- MINOR: sample: Add bc_rtt and bc_rttvar
- MINOR: quic: use real sending rate measurement
- MINOR: proxy: factorize send rate measurement
Before this patch, global sending rate was measured on the QUIC lower
layer just after sendto(). This meant that all QUIC frames were
accounted for, including non STREAM frames and also retransmission.
To have a better reflection of the application data transferred, move
the incrementation into the MUX layer. This allows to account only for
STREAM frames payload on their first emission.
MINOR: clock: replace the timeval start_time with start_time_ns
Now that "now" is no more a timeval, there's no point keeping a copy
of it as a timeval, let's also switch start_time to nanoseconds, it
simplifies operations.
MEDIUM: clock: replace timeval "now" with integer "now_ns"
This puts an end to the occasional confusion between the "now" date
that is internal, monotonic and not synchronized with the system's
date, and "date" which is the system's date and not necessarily
monotonic. Variable "now" was removed and replaced with a 64-bit
integer "now_ns" which is a counter of nanoseconds. It wraps every
585 years, so if all goes well (i.e. if humanity does not need
haproxy anymore in 500 years), it will just never wrap. This implies
that now_ns is never nul and that the zero value can reliably be used
as "not set yet" for a timestamp if needed. This will also simplify
date checks where it becomes possible again to do "date1<date2".
All occurrences of "tv_to_ns(&now)" were simply replaced by "now_ns".
Due to the intricacies between now, global_now and now_offset, all 3
had to be turned to nanoseconds at once. It's not a problem since all
of them were solely used in 3 functions in clock.c, but they make the
patch look bigger than it really is.
The clock_update_local_date() and clock_update_global_date() functions
are now much simpler as there's no need anymore to perform conversions
nor to round the timeval up or down.
The wrapping continues to happen by presetting the internal offset in
the short future so that the 32-bit now_ms continues to wrap 20 seconds
after boot.
The start_time used to calculate uptime can still be turned to
nanoseconds now. One interrogation concerns global_now_ms which is used
only for the freq counters. It's unclear whether there's more value in
using two variables that need to be synchronized sequentially like today
or to just use global_now_ns divided by 1 million. Both approaches will
work equally well on modern systems, the difference might come from
smaller ones. Better not change anyhting for now.
One benefit of the new approach is that we now have an internal date
with a resolution of the nanosecond and the precision of the microsecond,
which can be useful to extend some measurements given that timestamps
also have this resolution.
Instead we're using ns_to_sec(tv_to_ns(&now)) which allows the tv_sec
part to disappear. At this point, "now" is only used as a timeval in
clock.c where it is updated.
MEDIUM: tree-wide: replace timeval with nanoseconds in tv_accept and tv_request
Let's get rid of timeval in storage of internal timestamps so that they
are no longer mistaken for wall clock time. These were exclusively used
subtracted from each other or to/from "now" after being converted to ns,
so this patch removes the tv_to_ns() conversion to use them natively. Two
occurrences of tv_isge() were turned to a regular wrapping subtract.
MINOR: time: replace calls to tv_ms_elapsed() with a linear subtract
Instead of operating on {sec, usec} now we convert both operands to
ns then subtract them and convert to ms. This is a first step towards
dropping timeval from these timestamps.
Interestingly, tv_ms_elapsed() and tv_ms_remain() are no longer used at
all and could be removed.
In order to ease the transition away from the timeval used in internal
timestamps, let's first create a few functions and macro to return a
counter from a timeval and conversely, as well as ease the conversions
to/from ns/us/ms/sec to save the user from having to count zeroes and
to think about appending ULL in conversions.
BUG/MINOR: stats: report the correct start date in "show info"
The "show info" help for "Start_time_sec" says "Start time in seconds"
so it's definitely the start date in human format, not the internal one
that is solely used to compute uptime. Since commit 28360dc ("MEDIUM:
clock: force internal time to wrap early after boot"), both are split
apart since the start time takes into account the offset needed to cause
the early wraparound, so we must only use start_date here.
BUG/MEDIUM: tcpcheck: Don't eval custom expect rule on an empty buffer
The commit a664aa6a6 ("BUG/MINOR: tcpcheck: Be able to expect an empty
response") instroduced a regression for expect rules relying on a custom
function. Indeed, there is no check on the buffer to be sure it is not empty
before calling the custom function. But some of these functions expect to
have data and don't perform any test on the buffer emptiness.
So instead of fixing all custom functions, we just don't eval them if the
buffer is empty.
This patch must be backported but only if the commit above was backported
first.
SC_FL_SND_NEVERWAIT and SC_FL_SND_EXP_MORE flags have the same value. It is
not critical because these flags are only used to know if MSG_MORE flag must
be set on a send().
BUG/MEDIUM: spoe: Don't start new applet if there are enough idle ones
It is possible to start too many applets on sporadic burst of events after
an inactivity period. It is due to the way we estimate if a new applet must
be created or not. It is based on a frequency counter. We compare the events
processing rate against the number of events currently processed (in
progress or waiting to be processed). But we should also take care of the
number of idle applets.
We already track the number of idle applets, but it is global and not
per-thread. Thus we now also track the number of idle applets per-thread. It
is not a big deal because this fills a hole in the spoe_agent structure.
Thanks to this counter, we can refrain applets creation if there is enough
idle applets to handle currently processed events.
This patch should be backported to every stable versions.
BUG/MINOR: hlua: return wall-clock date, not internal date in core.now()
That's hopefully the last one affected by this. It was a bit trickier
because there's the promise in the doc that the date is monotonous, so
we continue to use now-start_time as the uptime value and add it to
start_date to get the current date. It was also emphasized by commit 28360dc ("MEDIUM: clock: force internal time to wrap early after boot"),
causing core.now() to return a date of Mar 20 on Apr 27. No backport is
needed.
BUG/MINOR: trace: show wall-clock date, not internal date in show activity
Yet another case where "now" was used instead of "date" for a publicly
visible date that was already incorrect and became worse after commit 28360dc ("MEDIUM: clock: force internal time to wrap early after boot").
No backport is needed.
BUG/MINOR: calltrace: fix 'now' being used in place of 'date'
Since commit 28360dc ("MEDIUM: clock: force internal time to wrap early
after boot") we have a much clearer distinction between 'now' (the internal,
drifting clock) and 'date' (the wall clock time). The calltrace code was
using "now" instead of "date" since the value is displayed to humans.
The parts affecting the DeviceAtlas addon were wrong actually, the
"now" variable was a local time_t in a file that's not compiled with
the haproxy binary (dadwsch). Only the fix to the calltrace is correct,
so better revert and fix the only one in a separate commit. No backport
is needed.
BUG/MINOR: opentracing: use 'date' instead of 'now' in debug output
The filter was using "now" in visible output in debug mode, that's
not correct, we should rather use "date" since it's visible. No
backport is needed as it was mostly emphasized by commit 28360dc
("MEDIUM: clock: force internal time to wrap early after boot")
in 2.8..
BUG/MINOR: activity: show wall-clock date, not internal date in show activity
Another case where "now" was used instead of "date" for a publicly visible
date that was already incorrect and became worse after commit 28360dc
("MEDIUM: clock: force internal time to wrap early after boot"). No
backport is needed.
BUG/MINOR: spoe: use "date" not "now" in debug messages
The debug messages were still emitted with a date taken from "now" instead
of "date", which was not correct a long time ago but which became worse in
2.8 since commit 28360dc ("MEDIUM: clock: force internal time to wrap early
after boot"). Let's fix it. No backport is needed.
BUG/MINOR: clock: fix a few occurrences of 'now' being used in place of 'date'
Since commit 28360dc ("MEDIUM: clock: force internal time to wrap early
after boot") we have a much clearer distinction between 'now' (the internal,
drifting clock) and 'date' (the wall clock time). There were still a few
places where 'now' was being used for human consumption.
BUG/MINOR: quic: fix race on quic_conns list during affinity rebind
Each quic_conn are attached in a global thread-local quic_conns list
used for "show quic" command. During thread rebinding, a connection is
detached from its local list instance and moved to its new thread list.
However this operation is not thread-safe and may cause a race
condition.
To fix this, only remove the connection from its list inside
qc_set_tid_affinity(). The connection is inserted only after in
qc_finalize_affinity_rebind() on the new thread instance thus prevented
a race condition. One impact of this is that a connection will be
invisible during rebinding for "show quic".
A connection must not transition to closing state in between this two
steps or else cleanup via quic_handle_stopping() may not miss it. To
ensure this, this patch relies on the previous commit :
commit d6646dddccb1aae08f60717b5b6743c513c37299
MINOR: quic: finalize affinity change as soon as possible
MINOR: quic: finalize affinity change as soon as possible
During accept, a quic-conn is rebind to a new thread. This process is
done in two times :
* first on the original thread via qc_set_tid_affinity()
* then on the newly assigned thread via qc_finalize_affinity_rebind()
Most quic_conn operations (I/O tasklet, task and quic_conn FD socket
read) are reactivated ony after the second step. However, there is a
possibility that datagrams are handled before it via quic_dgram_parse()
when using listener sockets. This does not seem to cause any issue but
this may cause unexpected behavior in the future.
To simplify this, qc_finalize_affinity_rebind() will be called both by
qc_xprt_start() and quic_dgram_parse(). Only one invocation will be
performed thanks to the new flag QUIC_FL_CONN_AFFINITY_CHANGED.
MINOR: mux-quic: do not allocate Tx buf for empty STREAM frame
Sometimes it may be necessary to send an empty STREAM frame to signal
clean stream closure with FIN bit set. Prior to this change, a Tx buffer
was allocated unconditionnally even if no data is transferred.
Most of the times, allocation was not performed due to an older buffer
reused. But if data were already acknowledge, a new buffer is allocated.
No memory leak occurs as the buffer is properly released when the empty
frame acknowledge is received. But this allocation is unnecessary and it
consumes a connexion Tx buffer for nothing.
Improve this by skipping buffer allocation if no data to transfer.
qcs_build_stream_frm() is now able to deal with a NULL out argument.
MINOR: mux-quic: do not set buffer for empty STREAM frame
Previous patch fixes an issue occurring with empty STREAM frames without
payload. The crash was hidden in part because buf/data fields of
qf_stream were set even if no payload is referenced. This was not the
true cause of the crash but to ease future debugging, a STREAM frame
built with no payload now has its buf and data fields set to NULL.
BUG/MINOR: quic: prevent buggy memcpy for empty STREAM
Sometimes it may be necessary to send empty STREAM frames with only the
FIN bit set. For these frames, memcpy is thus unnecessary as their
payload is empty. However, we did not prevent its invocation inside
quic_build_stream_frame().
Normally, memcpy invocation with length==0 is safe. However, there is an
extra condition in our function to handle data wrapping. For an empty
STREAM frame in the context of MUX emission, this is safe as the frame
points to a valid buffer which causes the wrapping condition to be false
and resulting in a memcpy with 0 length.
However, in the context of retransmission, this may lead to a crash.
Consider the following scenario : two STREAM frames A and B are
produced, one with payload and one empty with FIN set, pointing to the
same stream_desc buffer. If A is acknowledged by the peer, its buffer is
released as no more data is left in it. If B needs to be resent, the
wrapping condition will be messed up to a reuse of a freed buffer. Most
of the times, <wrap> will be a negative number, which results in a
memcpy invocation causing a buffer overflow.
To fix this, simply add an extra condition to skip memcpy and wrapping
check if STREAM frame length is null inside quic_build_stream_frame().
This crash is pretty rare as it relies on a lot of conditions difficult
to reproduce. It seems to be the cause for the latest crashes reported
under github issue #2120. In all the inspected dumps, the segfault
occurred during retransmission with an empty STREAM frame being used as
input. Thanks again to Tristan from Mangadex for his help and
investigation on it.
BUG/MEDIUM: mux-quic: improve streams fairness to prevent early timeout
Since the following mentioned patch, a send-list mechanism was
implemented to improve streams priorization on sending.
commit 20f2a425ffeda2e623aac4c702f4e44b1e122d1d
MAJOR: mux-quic: rework stream sending priorization
This is done to prevent the same streams to always be used as first ones
on emission. However there is still a flaw on the algorithm. Once put in
the send-list, a streams is not removed until it has sent all of its
content. When a stream transfers a large object, it will remain in the
send-list during all the transfer and will soon monopolize the first
place. the stream does never leave its position until the transfer is
finished and will monopolize the first place. Other streams behind won't
have the opportunity to advance on their own transfers due to a Tx
buffer exhaustion.
This situation is especially problematic if a small timeout client is
used. As some streams won't advance on their transfer for a long period
of time, they will be aborted due to a stream layer timeout client
causing a RESET_STREAM emission.
To fix this, during sending each stream with at least some bytes
transferred from its tx.buf to qc_stream_desc out buffer is put at the
end of the send-list. This ensures that on the next iteration streams
that cannot transfer anything will be used in priority.
This patch improves significantly h2load benchmarks for large objects
with several streams opened in parallel on a single connection. Without
it, errors may be reported by h2load for aborted streams. For example,
this improved the following scenario on a 10mbit/s link with a 10s
timeout client :
$ ./build/bin/h2load --npn-list h3 -t 1 -c 1 -m 30 -n 30 https://198.18.10.11:20443/?s=500k
This fix may help with the github issue #2004 where chrome browser stop
to use QUIC after receiving RESET_STREAM frames.
BUG/MEDIUM: mux-quic: do not emit RESET_STREAM for unknown length
Some HTX responses may not always contain a EOM block. For example this
is the case if content-length header is missing from the HTTP server
response. Stream termination is thus signaled to QUIC mux via shutw
callback. However, this is interpreted inconditionnally as an early
close by the mux with a RESET_STREAM emission. Most of the times, QUIC
clients report this as an error.
To fix this, check if htx.extra is set to HTX_UNKOWN_PAYLOAD_LENGTH for
a qcs instance. If true, shutw will never be used to emit a
RESET_STREAM. Instead, the stream will be closed properly with a FIN
STREAM frame. If all data were already transfered, an empty STREAM frame
is sent.
This fix may help with the github issue #2004 where chrome browser stop
to use QUIC after receiving RESET_STREAM frames.
This issue was reported by Vladimir Zakharychev. Thanks to him for his
help and testing. It was also reproduced locally using httpterm with the
query string "/?s=1k&b=0&C=1".
DEV: h2: support reading frame payload from a file
Now we can build a series of data frames by reading from a file and
chunking it into frames of requested length. It's mostly useful for
data frames (e.g. post). One way to announce these upfront is to
capture the output of curl use without content-length:
Then just change the 5th byte from the end from 1 to 0 to remove the
end-of-stream bit, it will allow to chain a file, then to send an
empty DATA frame with ES set :
$ (dev/h2/mkhdr.sh -i 1 -t data -d CHANGELOG;
dev/h2/mkhdr.sh -i 1 -t data -l 0 -f es) > h2-data-changelog.bin
Then post that to the server:
$ cat post-h2-nocl.bin h2-data-changelog.bin | nc 0 4446
It's conveniently encoded as 4 zeroes (when the operand is zero). It's
unclear when support for it was added into GAS, if at all; even a
not-so-old 2.27 doesn't know about it. Let's byte-encode it.
DEBUG: crash using an invalid opcode on x86/x86_64 instead of an invalid access
BUG_ON() calls currently trigger a segfault. This is more convenient
than abort() as it doesn't rely on any function call nor signal handler
and never causes non-unwindable stacks when opening cores. But it adds
quite some confusion in bug reports which are rightfully tagged "segv"
and do not instantly allow to distinguish real segv (e.g. null derefs)
from code asserts.
Some CPU architectures offer various crashing methods. On x86 we have
INT3 (0xCC), which stops into the debugger, and UD0/UD1/UD2. INT3 looks
appealing but for whatever reason (maybe signal handling somewhere) it
loses the last call point in the stack, making backtraces unusable. UD2
has the merit of being only 2 bytes and causing an invalid instruction,
which almost never happens normally, so it's easily distinguishable.
Here it was defined as a macro so that the line number in the core
matches the one where the BUG_ON() macro is called, and the debugger
shows the last frame exactly at its calligg point.
E.g. when calling "debug dev bug":
Program terminated with signal SIGILL, Illegal instruction.
#0 debug_parse_cli_bug (args=<optimized out>, payload=<optimized out>, appctx=<optimized out>, private=<optimized out>) at src/debug.c:408
408 BUG_ON(one > zero);
[Current thread is 1 (Thread 0x7f7a660cc1c0 (LWP 14238))]
(gdb) bt
#0 debug_parse_cli_bug (args=<optimized out>, payload=<optimized out>, appctx=<optimized out>, private=<optimized out>) at src/debug.c:408
#1 debug_parse_cli_bug (args=<optimized out>, payload=<optimized out>, appctx=<optimized out>, private=<optimized out>) at src/debug.c:402
#2 0x000000000061a69f in cli_parse_request (appctx=appctx@entry=0x181c0160) at src/cli.c:832
#3 0x000000000061af86 in cli_io_handler (appctx=0x181c0160) at src/cli.c:1035
#4 0x00000000006ca2f2 in task_run_applet (t=0x181c0290, context=0x181c0160, state=<optimized out>) at src/applet.c:449