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.
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).
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.
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.
Commit 986798718 ("DEBUG: cli: add "debug dev task" to show/wake/expire/kill
tasks and tasklets") broke the build on windows due to this:
src/debug.c:940:95: error: array subscript has type char [-Werror=char-subscripts]
940 | caller && may_access(caller) && may_access(caller->func) && isalnum(*caller->func) ? caller->func : "0",
| ^~~~~~~~~~~~~
It's classical on platforms which implement ctype.h as macros instead of
functions, let's cast it as uchar. No backport is needed.
The x509_v_err_str converter now outputs the numerical value as a string
when the corresponding constant name was not found.
Must be backported as far as 2.7.
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!
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.
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.
This should be backported up to 2.6.
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.
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.
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.
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.
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.
No backport is needed.
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.
It was a cut/paste typo during stream-interface to conn-stream
refactoring. sc_have_room() was used instead of sc_need_room().
This patch must be backported as far as 2.6.
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().
No backport needed.
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.
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.
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.
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.
No backport is needed.
This reverts commit aadcfc9ea6.
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.
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..
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.
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.
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.
No backport is needed.
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 d6646dddcc
MINOR: quic: finalize affinity change as soon as possible
This should be backported up to 2.7.
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.
This should be backported up to 2.7.
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.
This should be backported up to 2.6.
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.
This should be backported up to 2.6.
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.
This should be backported up to 2.6.
