From 979b86ecb9292bdcd57f99632749ac8689df7c82 Mon Sep 17 00:00:00 2001 From: Aram Sargsyan Date: Fri, 15 Sep 2023 10:03:29 +0000 Subject: [PATCH] Improve the "Duration (s)" field of the incoming xfers in stats channel Improve the "Duration (s)" field, so that it can show the duration of all the major states of an incoming zone transfer process, while they are taking place. In particular, it will now show the duration of the "Pending", "Refresh SOA" and "Deferred" states too, before the actual zone transfer starts. --- bin/named/statschannel.c | 10 ++++++---- doc/arm/reference.rst | 25 ++++++++++++++++--------- lib/dns/include/dns/zone.h | 14 ++++++++++++++ lib/dns/zone.c | 22 ++++++++++++++++++++++ 4 files changed, 58 insertions(+), 13 deletions(-) diff --git a/bin/named/statschannel.c b/bin/named/statschannel.c index fdf39dd849..8b482e3a46 100644 --- a/bin/named/statschannel.c +++ b/bin/named/statschannel.c @@ -1647,8 +1647,9 @@ xfrin_xmlrender(dns_zone_t *zone, void *arg) { TRY0(xmlTextWriterEndElement(writer)); TRY0(xmlTextWriterStartElement(writer, ISC_XMLCHAR "duration")); - if (is_running) { - isc_time_t start = dns_xfrin_getstarttime(xfr); + if (is_running || is_deferred || is_presoa || is_pending) { + isc_time_t start = is_running ? dns_xfrin_getstarttime(xfr) + : dns_zone_getxfrintime(zone); isc_time_t now = isc_time_now(); isc_time_t diff; uint32_t sec; @@ -2680,8 +2681,9 @@ xfrin_jsonrender(dns_zone_t *zone, void *arg) { json_object_object_add(xfrinobj, "tsigkeyname", NULL); } - if (is_running) { - isc_time_t start = dns_xfrin_getstarttime(xfr); + if (is_running || is_deferred || is_presoa || is_pending) { + isc_time_t start = is_running ? dns_xfrin_getstarttime(xfr) + : dns_zone_getxfrintime(zone); isc_time_t now = isc_time_now(); isc_time_t diff; uint32_t sec; diff --git a/doc/arm/reference.rst b/doc/arm/reference.rst index ea4ae03c77..4f74713693 100644 --- a/doc/arm/reference.rst +++ b/doc/arm/reference.rst @@ -7582,7 +7582,8 @@ Incoming Zone Transfers ``Pending`` The zone is flagged for a refresh, but the process is currently in the queue and will start shortly, or is in a waiting state - because of rate-limiting, see :any:`serial-query-rate`. + because of rate-limiting, see :any:`serial-query-rate`. The + ``Duration (s)`` timer starts before entering this state. ``Refresh SOA`` Sending a refresh SOA query to get the zone serial number, then @@ -7590,16 +7591,19 @@ Incoming Zone Transfers the ``SOA Query`` and ``Got SOA`` states will be skipped. Otherwise, the zone transfer procedure can still be initiated, and the SOA request will be attempted using the same transport as - the zone transfer. + the zone transfer. The ``Duration (s)`` timer restarts before + entering this state, and for each attempted primary server. ``Deferred`` The zone is going to be refreshed, but the process was deferred due to quota, see :any:`transfers-in` and - :any:`transfers-per-ns`. + :any:`transfers-per-ns`. The ``Duration (s)`` timer restarts before + entering this state. ``SOA Query`` Sending SOA query to get the zone serial number, then - follow with a zone transfer, if necessary. + follow with a zone transfer, if necessary. The ``Duration (s)`` + timer restarts before entering this state. ``Got SOA`` An answer for the SOA query from the previous step is @@ -7607,7 +7611,8 @@ Incoming Zone Transfers ``Initial SOA`` Waiting for the transfer to start, which is expected - to begin with an initial SOA record. + to begin with an initial SOA record. The ``Duration`` timer + restarts before entering this state. ``First Data`` Waiting for the first data record of the transfer. @@ -7668,10 +7673,12 @@ Incoming Zone Transfers ``Duration (s)`` (``duration``) 64 bit unsigned Integer. This is the time, in seconds, that - the transfer has been running so far. The clock starts after - the zone transfer process is initialized, and restarts shortly - after, when transport connection has been established and the - XFR request has been sent. + the current major state of the transfer process has been running so far. + The timer starts after the refresh SOA request is queued (before the + ``Pending`` state), then it restarts several times during the whole + process to indicate the duration of the current major state. See the + descriptions of the different states to find out the states, before which + this timer restarts. ``Messages Received`` (``nmsg``) 64 bit unsigned Integer. This is the number of DNS messages diff --git a/lib/dns/include/dns/zone.h b/lib/dns/include/dns/zone.h index c2ce8a7a5e..7df0f89a28 100644 --- a/lib/dns/include/dns/zone.h +++ b/lib/dns/include/dns/zone.h @@ -1479,6 +1479,20 @@ dns_zone_getsigresigninginterval(dns_zone_t *zone); * \li 'zone' to be a valid zone. */ +isc_time_t +dns_zone_getxfrintime(const dns_zone_t *zone); +/*%< + * Get the start time of the zone's latest major step before an incoming zone + * transfer is initiated. The time is set to the current time before the + * precursory SOA query is queued, then it gets reset when the query starts, + * when the query restarts (using another transport or another primary server), + * when an incoming zone transfer is initated and deferred, and, finally, when + * it gets started. + * + * Requires: + * \li 'zone' to be a valid zone. + */ + dns_transport_type_t dns_zone_getrequesttransporttype(dns_zone_t *zone); /*%< diff --git a/lib/dns/zone.c b/lib/dns/zone.c index fd4ab0546a..143e98d6b0 100644 --- a/lib/dns/zone.c +++ b/lib/dns/zone.c @@ -292,6 +292,7 @@ struct dns_zone { isc_time_t signingtime; isc_time_t nsec3chaintime; isc_time_t refreshkeytime; + isc_time_t xfrintime; uint32_t refreshkeyinterval; uint32_t refreshkeycount; uint32_t refresh; @@ -13870,6 +13871,10 @@ same_primary: queue_soa_query(zone); detach: + if (do_queue_xfrin) { + /* Shows in the statistics channel the duration of the step. */ + zone->xfrintime = isc_time_now(); + } UNLOCK_ZONE(zone); if (do_queue_xfrin) { queue_xfrin(zone); @@ -13902,6 +13907,9 @@ queue_soa_query(dns_zone_t *zone) { sq = isc_mem_get(zone->mctx, sizeof(*sq)); *sq = (struct soaquery){ .zone = NULL }; + /* Shows in the statistics channel the duration of the current step. */ + zone->xfrintime = isc_time_now(); + /* * Attach so that we won't clean up until the event is delivered. */ @@ -14099,6 +14107,9 @@ again: isc_result_totext(result)); goto skip_primary; } else { + /* Shows in the statistics channel the duration of the query. */ + zone->xfrintime = isc_time_now(); + if (isc_sockaddr_pf(&curraddr) == PF_INET) { inc_stats(zone, dns_zonestatscounter_soaoutv4); } else { @@ -14122,6 +14133,10 @@ cleanup: if (cancel) { cancel_refresh(zone); } + if (do_queue_xfrin) { + /* Shows in the statistics channel the duration of the step. */ + zone->xfrintime = isc_time_now(); + } UNLOCK_ZONE(zone); if (do_queue_xfrin) { queue_xfrin(zone); @@ -17573,6 +17588,13 @@ dns_zone_getsigresigninginterval(dns_zone_t *zone) { return (zone->sigresigninginterval); } +isc_time_t +dns_zone_getxfrintime(const dns_zone_t *zone) { + REQUIRE(DNS_ZONE_VALID(zone)); + + return (zone->xfrintime); +} + static void queue_xfrin(dns_zone_t *zone) { isc_result_t result;