Lua's `get_stats` function stopped working in
4cfb0019e6, due to the addition a new field
ST_F_PROTO without a corresponding entry in `stat_fields`.
Fix the issue by adding the entry, like
a46b142e88 did previously for a different field.
This patch fixes GitHub Issue #2174, it should be backported to 2.8.
Just like we have the uptime in "show info", let's add the boot time.
It's trivial to collect as it's just the difference between the ready
date and the start date, and will allow users to monitor this element
in order to take action before it starts becoming problematic. Here
the boot time is reported in milliseconds, so this allows to even
observe sub-second anomalies in startup delays.
When integrating the number of warnings in "show info" in 2.8 with commit
3c4a297d2 ("MINOR: stats: report the total number of warnings issued"),
the update of the trash buffer used by the Tainted flag got displaced
lower. There's no harm for now util someone adds a new metric requiring
a call to chunk_newstr() and gets both values merged. Let's move the
call to its location now.
When "optioon socket-stats" is used in a frontend, its listeners have
their own stats and will appear in the stats page. And when the stats
page has "stats show-legends", then a tooltip appears on each such
socket with ip:port and ID. The problem is that since QUIC arrived, it
was not possible to distinguish the TCP listeners from the QUIC ones
because no protocol indication was mentioned. Now we add a "proto"
legend there with the protocol name, so we can see "tcp4" or "quic6"
and figure how the socket is bound.
As discussed a few times over the years, it's quite difficult to know
how often we stop accepting connections because the global maxconn was
reached. This is not easy to know because when we reach the limit we
stop accepting but we don't know if incoming connections are pending,
so it's not possible to know how many were delayed just because of this.
However, an interesting equivalent metric consist in counting the number
of times an accepted incoming connection resulted in the limit being
reached. I.e. "we've accepted the last one for now". That doesn't imply
any other one got delayed but it's a factual indicator that something
might have been delayed. And by counting the number of such events, it
becomes easier to know whether some limits need to be adjusted because
they're reached often, or if it's exceptionally rare.
The metric is reported as a counter in show info and on the stats page
in the info section right next to "maxconn".
Now in "show info" we have a TotalWarnings field that reports the total
number of warnings issued since the process started. It's also reported
in the the stats page next to the uptime.
This was lost with commit f4258bdf3 ("MINOR: stats: Use the applet API to
write data"). When the buffer is almost full, the stats applet gives up.
When this happens, the applet must require more room. Otherwise, data in the
channel buffer are sent to the client but the applet is not woken up in
return.
It is a 2.8-specific bug, no backport needed.
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.
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.
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.
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.
This one is greatly inspired by "MINOR: server: change adm_st_chg_cause storage type".
While looking at current srv_op_st_chg_cause usage, it was clear that
the struct needed some cleanup since some leftovers from asynchronous server
state change updates were left behind and resulted in some useless code
duplication, and making the whole thing harder to maintain.
Two observations were made:
- by tracking down srv_set_{running, stopped, stopping} usage,
we can see that the <reason> argument is always a fixed statically
allocated string.
- check-related state change context (duration, status, code...) is
not used anymore since srv_append_status() directly extracts the
values from the server->check. This is pure legacy from when
the state changes were applied asynchronously.
To prevent code duplication, useless string copies and make the reason/cause
more exportable, we store it as an enum now, and we provide
srv_op_st_chg_cause() function to fetch the related description string.
HEALTH and AGENT causes (check related) are now explicitly identified to
make consumers like srv_append_op_chg_cause() able to fetch checks info
from the server itself if they need to.
Even though it doesn't look like it at first glance, this is more like
a cleanup than an actual code improvement:
Given that srv->adm_st_chg_cause has been used to exclusively store
static strings ever since it was implemented, we make the choice to
store it as an enum instead of a fixed-size string within server
struct.
This will allow to save some space in server struct, and will make
it more easily exportable (ie: event handlers) because of the
reduced memory footprint during handling and the ability to later get
the corresponding human-readable message when it's explicitly needed.
SC_FL_EOS flag is added to report the end-of-stream at the SC level. It will
be used to distinguish end of stream reported by the endoint, via the
SE_FL_EOS flag, and the abort triggered by the stream, via the
SC_FL_ABRT_DONE flag.
In this patch, the flag is defined and is systematically tested everywhere
SC_FL_ABRT_DONE is tested. It should be safe because it is never set.
Here again, it is just a flag renaming. In SC flags, there is no longer
shutdown for reads but aborts. For now this flag is set when a read0 is
detected. It is of couse not accurate. This will be changed later.
When the stats applet is executed while a shut is pending, the remaining
output data must always be consumed. Otherwise, this can prevent the stream
to exit, leading to a spinning loop on the applet.
It is 2.8-specific. No backport needed.
These ones are genenerally harmless on modern compilers because the
compiler checks them. While gcc optimizes them away without even
referencing strcpy(), clang prefers to call strcpy(). Nevertheless they
prevent from enabling stricter checks so better remove them altogether.
They were all replaced by strlcpy2() and the size of the destination
which is always known there.
In stats_dump_proxy_to_buffer() function, special care was taken when
dealing with servers dump.
Indeed, stats_dump_proxy_to_buffer() can be interrupted and resumed if
buffer space is not big enough to complete dump.
Thus, a reference is taken on the server being dumped in the hope that
the server will still be valid when the function resumes.
(to prevent the server from being freed in the meantime)
While this is now true thanks to:
- "BUG/MINOR: server/del: fix legacy srv->next pointer consistency"
We still have an issue: when resuming, saved server reference is not
dropped.
This prevents the server from being freed when we no longer use it.
Moreover, as the saved server might now be deleted
(SRV_F_DELETED flag set), the current deleted server may still be dumped
in the stats and while this is not a bug, this could be misleading for
the user.
Let's add a px_st variable to detect if the stats_dump_proxy_to_buffer()
is being resumed at the STAT_PX_ST_SV stage: perform some housekeeping
to skip deleted servers and properly drop the reference on the saved
server.
This commit depends on:
- "MINOR: server: add SRV_F_DELETED flag"
- "BUG/MINOR: server/del: fix legacy srv->next pointer consistency"
This should be backported up to 2.6
The purpose of this patch is only a one-to-one replacement, as far as
possible.
CF_SHUTR(_NOW) and CF_SHUTW(_NOW) flags are now carried by the
stream-connecter. CF_ prefix is replaced by SC_FL_ one. Of course, it is not
so simple because at many places, we were testing if a channel was shut for
reads and writes in same time. To do the same, shut for reads must be tested
on one side on the SC and shut for writes on the other side on the opposite
SC. A special care was taken with process_stream(). flags of SCs must be
saved to be able to detect changes, just like for the channels.
Thanks to the previous patch, it is now possible for applets to not set the
CF_EOI flag on the channels. On this point, the applets get closer to the
muxes.
In commit c2c043ed4 ("BUG/MEDIUM: stats: Consume the request except when
parsing the POST payload"), a change about applet was pushed too early. The
applet must still call cf_shutr() when the response is fully sent. It is
planned to rely on SE_FL_EOS flag, just like connections. But it is not
possible for now.
However, at first glance, this bug has no visible effect.
It is 2.8-specific. No backport needed.
The stats applet is designed to consume the request at the end, when it
finishes to send the response. And during the response forwarding, because
the request is not consumed, the applet states it will not consume
data. This avoid to wake the applet up in loop. When it finishes to send the
response, the request is consumed.
For POST requests, there is no issue because the response is small
enough. It is sent in one time and must be processed by HTTP analyzers. Thus
the forwarding is not performed by the applet itself. The applet is always
able to consume the request, regardless the payload length.
But for other requests, it may be an issue. If the response is too big to be
sent in one time and if the requests is not fully received when the response
headers are sent, the applet may be blocked infinitely, not consuming the
request. Indeed, in the case the applet will be switched in infinite forward
mode, the request will not be consumed immediately. At the end, the request
buffer is flushed. But if some data must still be received, the applet is not
woken up because it is still in a "not-consuming" mode.
So, to fix the issue, we must take care to re-enable data consuming when the
end of the response is reached.
This patch must be backported as far as 2.6.
It was done by hand by callers when a shutdown for read or write was
performed. It is now always handled by the functions performing the
shutdown. This way the callers don't take care of it. This will avoid some
bugs.
For an unknown reason in the change of uptime calculation for the HTML
page didn't make it to commit 6093ba47c ("BUG/MINOR: clock: do not mix
wall-clock and monotonic time in uptime calculation"). Let's address it
as well otherwise the stats page will display an incorrect uptime.
No backport needed unless the patch above is backported.
We've had a start date even before the internal monotonic clock existed,
but once the monotonic clock was added, the start date was not updated
to distinguish the wall clock time units and the internal monotonic time
units. The distinction is important because both clocks do not necessarily
progress at the same speed. The very rare occurrences of the wall-clock
date are essentially for human consumption and communication with third
parties (e.g. report the start date in "show info" for monitoring
purposes). However currently this one is also used to measure the distance
to "now" as being the process' uptime. This is actually not correct. It
only works because for now the two dates are initialized at the exact
same instant at boot but could still be wrong if the system's date shows
a big jump backwards during startup for example. In addition the current
situation prevents us from enforcing an abritrary offset at boot to reveal
some heisenbugs.
This patch adds a new "start_time" at boot that is set from "now" and is
used in uptime calculations. "start_date" instead is now set from "date"
and will always reflect the system date for human consumption (e.g. in
"show info"). This way we're now sure that any drift of the internal
clock relative to the system date will not impact the reported uptime.
This could possibly be backported though it's unlikely that anyone has
ever noticed the problem.
Due to multithreading concurrency, it is difficult at this time to figure
out how this counter may become negative. This simple patch only checks this
will never be the case.
This issue arrives with this commit:
"9969adbcdc MINOR: stats: add by HTTP version cumulated number of sessions and requests"
So, this patch should be backported when the latter has been backported.
When stats_putchk() fails to peform the dump because available data space in
htx is less than the number of bytes pending in the dump buffer, we wait
for more room in the htx (ie: sc_need_room()) to retry the dump attempt
on the next applet invocation.
To provide consistent output, we have to make sure that the stat ctx is not
updated (or at least correctly reverted) in case stats_putchk() fails so
that the new dumping attempt behaves just like the previous (failed) one.
STAT_STARTED is not following this logic, the flag is set in
stats_dump_fields_json() as soon as some data is written to the output buffer.
It's done too early: we need to delay this step after the stats_putchk() has
successfully returned if we want to correctly handle the retries attempts.
Because of this, JSON output could suffer from extraneous ',' characters which
could make json parsers unhappy.
For example, this is the kind of errors you could get when using
`python -m json.tool` on such badly formatted outputs:
"Expecting value: line 1 column 2 (char 1)"
Unfortunately, fixing this means that the flag needs to be enabled at
multiple places, which is what we're doing in this patch.
(in stats_dump_proxy_to_buffer() where stats_dump_one_line() is involved
by underlying stats_dump_{fe,li,sv,be} functions)
Thereby, this raises the need for a cleanup to reduce code duplication around
stats_dump_proxy_to_buffer() function and simplify things a bit.
It could be backported to 2.6 and 2.7
In ("MINOR: stats: introduce stats field ctx"), we forgot
to apply the patch to servers.
This prevents "BUG/MINOR: stats: fix show stat json buffer limitation"
from working with servers dump.
We're adding the missing part related to servers dump.
This commit should be backported with the aforementioned commits.
When ctx->field was introduced with ("MINOR: stats: introduce stats field ctx")
a mistake was made for the STAT_PX_ST_LI state in stats_dump_proxy_to_buffer():
current_field reset is placed after the for loop, ie: after multiple lines
are dumped. Instead it should be placed right after each li line is dumped.
This could cause some output inconsistencies (missing fields), especially when
http dump is used with JSON output and "socket-stats" option is enabled
on the proxy, because when htx is full we restore the ctx->field with
current_field (which contains outdated value in this case).
This should be backported with ("MINOR: stats: introduce stats field ctx")
In ("BUG/MEDIUM: stats: Rely on a local trash buffer to dump the stats"),
we forgot to apply the patch in resolvers.c which provides the
stats_dump_resolvers() function that is involved when dumping with "resolvers"
domain.
As a consequence, resolvers dump was broken because stats_dump_one_line(),
which is used in stats_dump_resolv_to_buffer(), implicitely uses trash_chunk
from stats.c to prepare the dump, and stats_putchk() is then called with
global trash (currently empty) as output data.
Given that trash_dump variable is static and thus only available within stats.c
we change stats_putchk() function prototype so that the function does not take
the output buffer as an argument. Instead, stats_putchk() will implicitly use
the local trash_dump variable declared in stats.c.
It will also prevent further mixups between stats_dump_* functions and
stats_putchk().
This needs to be backported with ("BUG/MEDIUM: stats: Rely on a local trash
buffer to dump the stats")
In ("BUG/MINOR: stats: use proper buffer size for http dump"),
we used trash.size as source buffer size before applying the htx
overhead computation.
It is safer to use res->buf.size instead since res_htx (which is <htx> argument
passed to stats_putchk() in http context) is made from res->buf:
in http_stats_io_handler:
| res_htx = htx_from_buf(&res->buf);
This will prevent the hang bug from showing up again if res->buf.size were to be
less than trash.size (which is set according to tune.bufsize).
This should be backported with ("BUG/MINOR: stats: use proper buffer size for http dump")
The maxconn is set per bind line so let's move it there. This might
possibly even slightly reduce inter-thread contention since this one
is read-mostly and it was stored next to nbconn which changes for
each connection setup or teardown.
Add cum_sess_ver[] new array of counters to count the number of cumulated
HTTP sessions by version (h1, h2 or h3).
Implement proxy_inc_fe_cum_sess_ver_ctr() to increment these counter.
This function is called each a HTTP mux is correctly initialized. The QUIC
must before verify the application operations for the mux is for h3 before
calling proxy_inc_fe_cum_sess_ver_ctr().
ST_F_SESS_OTHER stat field for the cumulated of sessions others than
HTTP sessions is deduced from ->cum_sess_ver counter (for all the session,
not only HTTP sessions) from which the HTTP sessions counters are substracted.
Add cum_req[] new array of counters to count the number of cumulated HTTP
requests by version and others than HTTP requests. This new member replace ->cum_req.
Modify proxy_inc_fe_req_ctr() which increments these counters to pass an HTTP
version, 0 special values meaning "other than an HTTP request". This is the case
for instance for syslog.c from which proxy_inc_fe_req_ctr() is called with 0
as version parameter.
ST_F_REQ_TOT stat field compputing for the cumulated number of requests is modified
to count the sum of all the cum_req[] counters.
As this patch is useful for QUIC, it must be backported to 2.7.
In an attempt to fix GH #1873, ("BUG/MEDIUM: stats: Rely on a local trash
buffer to dump the stats") explicitly reduced output buffer size to leave
enough space for htx overhead under http context.
Github user debtsandbooze, who first reported the issue, came back to us
and said he was still able to make the http dump "hang" with the new fix.
After some tests, it became clear that htx_add_data_atonce() could fail from
time to time in stats_putchk(), even if htx was completely empty:
In http context, buffer size is maxed out at channel_htx_recv_limit().
Unfortunately, channel_htx_recv_limit() is not what we're looking for here
because limit() doesn't compute the proper htx overhead.
Using buf_room_for_htx_data() instead of channel_htx_recv_limit() to compute
max "usable" data space seems to be the last piece of work required for
the previous fix to work properly.
This should be backported everywhere the aforementioned commit is.
During multiple tests we've already noticed that shared stats counters
have become a real bottleneck under large thread counts. With QUIC it's
pretty visible, with qc_snd_buf() taking 2.5% of the CPU on a 48-thread
machine at only 25 Gbps, and this CPU is entirely spent in the atomic
increment of the byte count and byte rate. It's also visible in H1/H2
but slightly less since we're working with larger buffers, hence less
frequent updates. These counters are exclusively used to report the
byte count in "show info" and the byte rate in the stats.
Let's move them to the thread_ctx struct and make the stats reader
just collect each thread's stats when requested. That's way more
efficient than competing on a single cache line.
After this, qc_snd_buf has totally disappeared from the perf profile
and tests made in h1 show roughly 1% performance increase on small
objects.
CF_READ_NULL flag is not really useful and used. It is a transient event
used to wakeup the stream. As we will see, all read events on a channel may
be resumed to only one and are all used to wake up the stream.
In this patch, we introduce CF_READ_EVENT flag as a replacement to
CF_READ_NULL. There is no breaking change for now, it is just a
rename. Gradually, other read events will be merged with this one.
The same change was already performed for the cli. The stats applet and the
prometheus exporter are also concerned. Both use the stats API and rely on
pool functions to get total pool usage in bytes. pool_total_allocated() and
pool_total_used() must return 64 bits unsigned integer to avoid any wrapping
around 4G.
This may be backported to all versions.
It is possible to block the stats applet if a line exceeds the free space in
the responsse buffer while the buffer is empty. It is only an issue in HTTP
becaues of the HTX overhead and, AFAIK, only with json output.
In this case, the applet is unable to write anything in the response buffer
and waits for some free space to proceed further. On the other hand, because
the response channel is empty, nothing is sent and thus no space can be
freed. At this stage, the stream and the applet are blocked waiting for the
other side.
To avoid this situation, we must take care to not dump a line exceeding the
free space in the HTX message. It means we cannot rely anymore on the global
trash buffer. At least, not directly. The trick is to use a local trash
buffer, mapped on the global one but with a different size. We use b_make()
to do so. The local trash buffer is thread local to avoid any concurrency
issue.
It is a valid fix. However it could be good to review the internal API of
the stats applet to not rely on a global variable.
This patch should solve the #1873. It must be backported at least as far as
2.6. Older versions must be evaluated first but it is probably possible to
hit this bug with long proxy/server names.
This is a follow up of "BUG/MINOR: stats: fix show stat json buffer limitation"
However this time this is purely preemptive as we did not reach the buffer
limitation yet. But now is the proper time so that this won't be an issue
in the upcoming versions.
No backport needed.
json output type is a lot more verbose than other output types.
Because of this and the increasing number of metrics implemented within
haproxy, we are starting to reach max bufsize limit (defaults to 16k)
when dumping stats to json since 2.6-dev1.
This results in stats output being truncated with
"[{"errorStr":"output buffer too short"}]"
This was reported by Gabriel in #1964.
Thanks to "MINOR: stats: introduce stats field ctx", we can now make
multipart (using multiple buffers) dumping, in case a single buffer is not big
enough to hold the complete stat line.
For now, only stats_dump_fields_json() makes use of it as it is by
far the most verbose stats output type.
(csv, typed and html outputs should be good for a while and may use this
capability if the need arises in some distant future)
--
It could be backported to 2.6 and 2.7.
This commit depends on:
- MINOR: stats: provide ctx for dumping functions
- MINOR: stats: introduce stats field ctx
Add a new value in stats ctx: field.
Implement field support in line dumping parent functions
stats_print_proxy_field_json() and stats_dump_proxy_to_buffer().
This will allow child dumping functions to support partial line dumping
when needed. ie: when dumping buffer is exhausted: do a partial send and
wait for a new buffer to finish the dump. Thanks to field ctx, the function
can start dumping where it left off on previous (unterminated) invokation.
This is a minor refactor to allow stats_dump_info_* and stats_dump_fields_*
functions to directly access stat ctx pointer instead of explicitly
passing stat ctx struct members to them.
This will allow dumping functions to benefit from upcoming ctx updates.
This patch introduces haproxy_backend_agg_check_status metric
as we wanted in 42d7c402d but with the right data source.
This patch could be backported as far as 2.4.
