upstream/bind9
1
0
Fork 0
mirror of https://github.com/isc-projects/bind9.git synced 2026-06-09 14:02:05 -04:00
Code Issues Projects Releases Packages Wiki Activity Actions

chg: usr: Set logging category for notify/xfer-in related messages

Browse source 
Some 'notify' and 'xfer-in' related log messages were logged at the
'general' category instead of their own category. This has been fixed.

Closes #2730

Merge branch '2730-logging-category-for-notify-and-xfer-related-messages' into 'main'

See merge request isc-projects/bind9!9451
This commit is contained in:
Arаm Sаrgsyаn 2024-09-17 15:52:20 +00:00
commit 796f886173
1 changed files with 181 additions and 146 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

327
lib/dns/zone.c
View file

@ -844,6 +844,9 @@ zone_settimer(dns_zone_t *, isc_time_t *);
static void
cancel_refresh(dns_zone_t *);
static void
zone_debuglogc(dns_zone_t *zone, isc_logcategory_t category, const char *me,
int debuglevel, const char *fmt, ...);
static void
zone_debuglog(dns_zone_t *zone, const char *, int debuglevel, const char *msg,
...) ISC_FORMAT_PRINTF(4, 5);
static void
@ -11418,8 +11421,9 @@ zone_refresh(dns_zone_t *zone) {
if (dns_remote_addresses(&zone->primaries) == NULL) {
DNS_ZONE_SETFLAG(zone, DNS_ZONEFLG_NOPRIMARIES);
if ((oldflags & DNS_ZONEFLG_NOPRIMARIES) == 0) {
dns_zone_log(zone, ISC_LOG_ERROR,
"cannot refresh: no primaries");
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_ERROR,
"cannot refresh: no primaries");
}
return;
}
@ -11438,9 +11442,9 @@ zone_refresh(dns_zone_t *zone) {
0);
result = isc_time_nowplusinterval(&zone->refreshtime, &i);
if (result != ISC_R_SUCCESS) {
dns_zone_log(zone, ISC_LOG_WARNING,
"isc_time_nowplusinterval() failed: %s",
isc_result_totext(result));
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_WARNING,
"isc_time_nowplusinterval() failed: %s",
isc_result_totext(result));
}
/*
@ -12774,9 +12778,8 @@ zone_notify(dns_zone_t *zone, isc_time_t *now) {
(void)dns_view_gettransport(view, DNS_TRANSPORT_TLS,
tlsname, &transport);
dns_zone_logc(
zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"got TLS configuration for zone transfer");
notify_log(zone, ISC_LOG_INFO,
"got TLS configuration for a notify");
}
/* TODO: glue the transport to the notify */
@ -13833,16 +13836,18 @@ refresh_callback(void *arg) {
case ISC_R_TIMEDOUT:
if (!DNS_ZONE_FLAG(zone, DNS_ZONEFLG_NOEDNS)) {
DNS_ZONE_SETFLAG(zone, DNS_ZONEFLG_NOEDNS);
dns_zone_log(zone, ISC_LOG_DEBUG(1),
"refresh: timeout retrying without EDNS "
"primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_DEBUG(1),
"refresh: timeout retrying without EDNS "
"primary %s (source %s)",
primary, source);
goto same_primary;
} else if (!dns_request_usedtcp(request)) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: retry limit for "
"primary %s exceeded (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"refresh: retry limit for "
"primary %s exceeded (source %s)",
primary, source);
/* Try with secondary with TCP. */
if ((zone->type == dns_zone_secondary ||
zone->type == dns_zone_mirror ||
@ -13858,21 +13863,22 @@ refresh_callback(void *arg) {
DNS_ZONEFLG_SOABEFOREAXFR);
goto tcp_transfer;
}
dns_zone_log(zone, ISC_LOG_DEBUG(1),
"refresh: skipped tcp fallback "
"as primary %s (source %s) is "
"unreachable (cached)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_DEBUG(1),
"refresh: skipped tcp fallback "
"as primary %s (source %s) is "
"unreachable (cached)",
primary, source);
}
goto next_primary;
}
FALLTHROUGH;
default:
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: failure trying primary "
"%s (source %s): %s",
primary, source,
isc_result_totext(dns_request_getresult(request)));
result = dns_request_getresult(request);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: failure trying primary "
"%s (source %s): %s",
primary, source, isc_result_totext(result));
goto next_primary;
}
@ -13880,10 +13886,10 @@ refresh_callback(void *arg) {
&msg);
result = dns_request_getresponse(request, msg, 0);
if (result != ISC_R_SUCCESS) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: failure trying primary "
"%s (source %s): %s",
primary, source, isc_result_totext(result));
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: failure trying primary "
"%s (source %s): %s",
primary, source, isc_result_totext(result));
goto next_primary;
}
@ -13897,10 +13903,10 @@ refresh_callback(void *arg) {
isc_buffer_init(&rb, opcode, sizeof(opcode));
(void)dns_opcode_totext(msg->opcode, &rb);
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: "
"unexpected opcode (%.*s) from %s (source %s)",
(int)rb.used, opcode, primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: "
"unexpected opcode (%.*s) from %s (source %s)",
(int)rb.used, opcode, primary, source);
goto next_primary;
}
@ -13919,28 +13925,30 @@ refresh_callback(void *arg) {
msg->rcode == dns_rcode_notimp ||
(msg->rcode == dns_rcode_formerr && msg->opt == NULL)))
{
dns_zone_log(zone, ISC_LOG_DEBUG(1),
"refresh: rcode (%.*s) retrying without "
"EDNS primary %s (source %s)",
(int)rb.used, rcode, primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_DEBUG(1),
"refresh: rcode (%.*s) retrying without "
"EDNS primary %s (source %s)",
(int)rb.used, rcode, primary, source);
DNS_ZONE_SETFLAG(zone, DNS_ZONEFLG_NOEDNS);
goto same_primary;
}
if (!DNS_ZONE_FLAG(zone, DNS_ZONEFLG_NOEDNS) &&
msg->rcode == dns_rcode_badvers)
{
dns_zone_log(zone, ISC_LOG_DEBUG(1),
"refresh: rcode (%.*s) retrying without "
"EDNS EXPIRE OPTION primary %s "
"(source %s)",
(int)rb.used, rcode, primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_DEBUG(1),
"refresh: rcode (%.*s) retrying without "
"EDNS EXPIRE OPTION primary %s "
"(source %s)",
(int)rb.used, rcode, primary, source);
DNS_ZONE_SETFLAG(zone, DNS_ZONEFLG_NOEDNS);
goto same_primary;
}
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: unexpected rcode (%.*s) from "
"primary %s (source %s)",
(int)rb.used, rcode, primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: unexpected rcode (%.*s) from "
"primary %s (source %s)",
(int)rb.used, rcode, primary, source);
/*
* Perhaps AXFR/IXFR is allowed even if SOA queries aren't.
*/
@ -13962,20 +13970,22 @@ refresh_callback(void *arg) {
zone->type == dns_zone_mirror ||
zone->type == dns_zone_redirect)
{
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: truncated UDP answer, "
"initiating TCP zone xfer "
"for primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"refresh: truncated UDP answer, "
"initiating TCP zone xfer "
"for primary %s (source %s)",
primary, source);
DNS_ZONE_SETFLAG(zone, DNS_ZONEFLG_SOABEFOREAXFR);
goto tcp_transfer;
} else {
INSIST(zone->type == dns_zone_stub);
if (dns_request_usedtcp(request)) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: truncated TCP response "
"from primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"refresh: truncated TCP response "
"from primary %s (source %s)",
primary, source);
goto next_primary;
}
DNS_ZONE_SETFLAG(zone, DNS_ZONEFLG_USEVC);
@ -13987,10 +13997,10 @@ refresh_callback(void *arg) {
* If non-auth, log and try the next primary
*/
if ((msg->flags & DNS_MESSAGEFLAG_AA) == 0) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: non-authoritative answer from "
"primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: non-authoritative answer from "
"primary %s (source %s)",
primary, source);
goto next_primary;
}
@ -14003,10 +14013,10 @@ refresh_callback(void *arg) {
* There should not be a CNAME record at top of zone.
*/
if (cnamecnt != 0) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: CNAME at top of zone "
"in primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: CNAME at top of zone "
"in primary %s (source %s)",
primary, source);
goto next_primary;
}
@ -14014,10 +14024,10 @@ refresh_callback(void *arg) {
* If referral, log and try the next primary;
*/
if (soacnt == 0 && soacount == 0 && nscount != 0) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: referral response "
"from primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: referral response "
"from primary %s (source %s)",
primary, source);
goto next_primary;
}
@ -14025,10 +14035,10 @@ refresh_callback(void *arg) {
* If nodata, log and try the next primary;
*/
if (soacnt == 0 && (nscount == 0 || soacount != 0)) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: NODATA response "
"from primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: NODATA response "
"from primary %s (source %s)",
primary, source);
goto next_primary;
}
@ -14036,10 +14046,10 @@ refresh_callback(void *arg) {
* Only one soa at top of zone.
*/
if (soacnt != 1) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: answer SOA count (%d) != 1 "
"from primary %s (source %s)",
soacnt, primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: answer SOA count (%d) != 1 "
"from primary %s (source %s)",
soacnt, primary, source);
goto next_primary;
}
@ -14051,17 +14061,17 @@ refresh_callback(void *arg) {
dns_rdatatype_soa, dns_rdatatype_none,
NULL, &rdataset);
if (result != ISC_R_SUCCESS) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: unable to get SOA record "
"from primary %s (source %s)",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: unable to get SOA record "
"from primary %s (source %s)",
primary, source);
goto next_primary;
}
result = dns_rdataset_first(rdataset);
if (result != ISC_R_SUCCESS) {
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: dns_rdataset_first() failed");
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refresh: dns_rdataset_first() failed");
goto next_primary;
}
@ -14077,11 +14087,11 @@ refresh_callback(void *arg) {
NULL, NULL);
RUNTIME_CHECK(result == ISC_R_SUCCESS);
RUNTIME_CHECK(dbsoacount > 0U);
zone_debuglog(zone, __func__, 1, "serial: new %u, old %u",
serial, oldserial);
zone_debuglogc(zone, DNS_LOGCATEGORY_XFER_IN, __func__, 1,
"serial: new %u, old %u", serial, oldserial);
} else {
zone_debuglog(zone, __func__, 1,
"serial: new %u, old not loaded", serial);
zone_debuglogc(zone, DNS_LOGCATEGORY_XFER_IN, __func__, 1,
"serial: new %u, old not loaded", serial);
}
if (!DNS_ZONE_FLAG(zone, DNS_ZONEFLG_LOADED) ||
@ -14091,15 +14101,16 @@ refresh_callback(void *arg) {
if (dns_zonemgr_unreachable(zone->zmgr, &curraddr,
&zone->sourceaddr, &now))
{
dns_zone_log(zone, ISC_LOG_INFO,
"refresh: skipping %s as primary %s "
"(source %s) is unreachable (cached)",
(zone->type == dns_zone_secondary ||
zone->type == dns_zone_mirror ||
zone->type == dns_zone_redirect)
? "zone transfer"
: "NS query",
primary, source);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"refresh: skipping %s as primary %s "
"(source %s) is unreachable (cached)",
(zone->type == dns_zone_secondary ||
zone->type == dns_zone_mirror ||
zone->type == dns_zone_redirect)
? "zone transfer"
: "NS query",
primary, source);
goto next_primary;
}
tcp_transfer:
@ -14142,12 +14153,14 @@ refresh_callback(void *arg) {
goto next_primary;
} else {
if (!DNS_ZONE_OPTION(zone, DNS_ZONEOPT_MULTIMASTER)) {
dns_zone_log(zone, ISC_LOG_INFO,
"serial number (%u) "
"received from primary %s < ours (%u)",
soa.serial, primary, oldserial);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"serial number (%u) "
"received from primary %s < ours (%u)",
soa.serial, primary, oldserial);
} else {
zone_debuglog(zone, __func__, 1, "ahead");
zone_debuglogc(zone, DNS_LOGCATEGORY_XFER_IN, __func__,
1, "ahead");
}
dns_remote_mark(&zone->primaries, true);
goto next_primary;
@ -14275,8 +14288,8 @@ soa_query(void *arg) {
}
again:
dns_zone_log(
zone, ISC_LOG_DEBUG(3),
dns_zone_logc(
zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_DEBUG(3),
"soa_query: remote server current address index %d count %d",
zone->primaries.curraddr, zone->primaries.addrcnt);
INSIST(dns_remote_count(&zone->primaries) > 0);
@ -14301,8 +14314,9 @@ again:
if (result != ISC_R_SUCCESS) {
char namebuf[DNS_NAME_FORMATSIZE];
dns_name_format(keyname, namebuf, sizeof(namebuf));
dns_zone_log(zone, ISC_LOG_ERROR,
"unable to find key: %s", namebuf);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_ERROR, "unable to find key: %s",
namebuf);
goto skip_primary;
}
}
@ -14312,8 +14326,9 @@ again:
char addrbuf[ISC_NETADDR_FORMATSIZE];
isc_netaddr_format(&primaryip, addrbuf,
sizeof(addrbuf));
dns_zone_log(zone, ISC_LOG_ERROR,
"unable to find TSIG key for %s", addrbuf);
dns_zone_logc(
zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_ERROR,
"unable to find TSIG key for %s", addrbuf);
goto skip_primary;
}
}
@ -14326,9 +14341,10 @@ again:
if (result != ISC_R_SUCCESS) {
char namebuf[DNS_NAME_FORMATSIZE];
dns_name_format(tlsname, namebuf, sizeof(namebuf));
dns_zone_log(zone, ISC_LOG_ERROR,
"unable to find TLS configuration: %s",
namebuf);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_ERROR,
"unable to find TLS configuration: %s",
namebuf);
goto skip_primary;
}
}
@ -14409,9 +14425,9 @@ again:
if (!DNS_ZONE_FLAG(zone, DNS_ZONEFLG_NOEDNS)) {
result = add_opt(message, udpsize, reqnsid, reqexpire);
if (result != ISC_R_SUCCESS) {
zone_debuglog(zone, __func__, 1,
"unable to add opt record: %s",
isc_result_totext(result));
zone_debuglogc(zone, DNS_LOGCATEGORY_XFER_IN, __func__,
1, "unable to add opt record: %s",
isc_result_totext(result));
}
}
@ -14424,9 +14440,9 @@ again:
zone->loop, refresh_callback, zone, &zone->request);
if (result != ISC_R_SUCCESS) {
zone_idetach(&(dns_zone_t *){ zone });
zone_debuglog(zone, __func__, 1,
"dns_request_create() failed: %s",
isc_result_totext(result));
zone_debuglogc(zone, DNS_LOGCATEGORY_XFER_IN, __func__, 1,
"dns_request_create() failed: %s",
isc_result_totext(result));
goto skip_primary;
} else {
/* Shows in the statistics channel the duration of the query. */
@ -15295,14 +15311,15 @@ dns_zone_notifyreceive(dns_zone_t *zone, isc_sockaddr_t *from,
{
UNLOCK_ZONE(zone);
if (msg->counts[DNS_SECTION_QUESTION] == 0) {
dns_zone_log(zone, ISC_LOG_NOTICE,
"NOTIFY with no "
"question section from: %s",
fromtext);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_NOTICE,
"NOTIFY with no question "
"section from: %s",
fromtext);
return (DNS_R_FORMERR);
}
dns_zone_log(zone, ISC_LOG_NOTICE,
"NOTIFY zone does not match");
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_NOTICE,
"NOTIFY zone does not match");
return (DNS_R_NOTIMP);
}
@ -15348,8 +15365,8 @@ dns_zone_notifyreceive(dns_zone_t *zone, isc_sockaddr_t *from,
/* Accept notify. */
} else if (i >= dns_remote_count(&zone->primaries)) {
UNLOCK_ZONE(zone);
dns_zone_log(zone, ISC_LOG_INFO,
"refused notify from non-primary: %s", fromtext);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"refused notify from non-primary: %s", fromtext);
inc_stats(zone, dns_zonestatscounter_notifyrej);
return (DNS_R_REFUSED);
}
@ -15386,10 +15403,11 @@ dns_zone_notifyreceive(dns_zone_t *zone, isc_sockaddr_t *from,
RUNTIME_CHECK(result == ISC_R_SUCCESS);
RUNTIME_CHECK(soacount > 0U);
if (isc_serial_le(serial, oldserial)) {
dns_zone_log(zone, ISC_LOG_INFO,
"notify from %s: "
"zone is up to date",
fromtext);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"notify from %s: "
"zone is up to date",
fromtext);
UNLOCK_ZONE(zone);
return (ISC_R_SUCCESS);
}
@ -15406,24 +15424,28 @@ dns_zone_notifyreceive(dns_zone_t *zone, isc_sockaddr_t *from,
zone->notifyfrom = *from;
UNLOCK_ZONE(zone);
if (have_serial) {
dns_zone_log(zone, ISC_LOG_INFO,
"notify from %s: serial %u: refresh in "
"progress, refresh check queued",
fromtext, serial);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"notify from %s: "
"serial %u: refresh in progress, "
"refresh check queued",
fromtext, serial);
} else {
dns_zone_log(zone, ISC_LOG_INFO,
"notify from %s: refresh in progress, "
"refresh check queued",
fromtext);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_INFO,
"notify from %s: "
"refresh in progress, "
"refresh check queued",
fromtext);
}
return (ISC_R_SUCCESS);
}
if (have_serial) {
dns_zone_log(zone, ISC_LOG_INFO, "notify from %s: serial %u",
fromtext, serial);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"notify from %s: serial %u", fromtext, serial);
} else {
dns_zone_log(zone, ISC_LOG_INFO, "notify from %s: no serial",
fromtext);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN, ISC_LOG_INFO,
"notify from %s: no serial", fromtext);
}
zone->notifyfrom = *from;
UNLOCK_ZONE(zone);
@ -15856,6 +15878,17 @@ dns_zone_log(dns_zone_t *zone, int level, const char *fmt, ...) {
va_end(ap);
}
static void
zone_debuglogc(dns_zone_t *zone, isc_logcategory_t category, const char *me,
int debuglevel, const char *fmt, ...) {
int level = ISC_LOG_DEBUG(debuglevel);
va_list ap;
va_start(ap, fmt);
dns_zone_logv(zone, category, level, me, fmt, ap);
va_end(ap);
}
static void
zone_debuglog(dns_zone_t *zone, const char *me, int debuglevel, const char *fmt,
...) {
@ -17703,10 +17736,11 @@ again:
ZONEDB_UNLOCK(&zone->dblock, isc_rwlocktype_read);
if (result == ISC_R_SUCCESS) {
if (soacount != 1) {
dns_zone_log(zone, ISC_LOG_ERROR,
"transferred zone "
"has %d SOA records",
soacount);
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_ERROR,
"transferred zone "
"has %d SOA records",
soacount);
if (DNS_ZONE_FLAG(zone, DNS_ZONEFLG_HAVETIMERS))
{
zone->refresh = DNS_ZONE_DEFAULTREFRESH;
@ -17717,9 +17751,10 @@ again:
goto next_primary;
}
if (nscount == 0) {
dns_zone_log(zone, ISC_LOG_ERROR,
"transferred zone "
"has no NS records");
dns_zone_logc(zone, DNS_LOGCATEGORY_XFER_IN,
ISC_LOG_ERROR,
"transferred zone "
"has no NS records");
if (DNS_ZONE_FLAG(zone, DNS_ZONEFLG_HAVETIMERS))
{
zone->refresh = DNS_ZONE_DEFAULTREFRESH;