]>
Commit | Line | Data |
---|---|---|
6644c1c7 MT |
1 | From 25cf5e373eb41c088d4ee5e625209c4cf6a5659e Mon Sep 17 00:00:00 2001 |
2 | From: Simon Kelley <simon@thekelleys.org.uk> | |
3 | Date: Fri, 9 Jan 2015 15:53:03 +0000 | |
5f206778 | 4 | Subject: [PATCH 27/87] Add --log-queries=extra option for more complete |
6644c1c7 MT |
5 | logging. |
6 | ||
7 | --- | |
8 | CHANGELOG | 3 +++ | |
9 | man/dnsmasq.8 | 5 ++++- | |
10 | src/cache.c | 11 ++++++++++- | |
11 | src/config.h | 1 + | |
12 | src/dnsmasq.c | 5 +++++ | |
13 | src/dnsmasq.h | 9 +++++++-- | |
14 | src/dnssec.c | 14 +++++++------- | |
15 | src/forward.c | 30 ++++++++++++++++++++++++++---- | |
16 | src/option.c | 11 +++++++++-- | |
17 | 9 files changed, 72 insertions(+), 17 deletions(-) | |
18 | ||
19 | diff --git a/CHANGELOG b/CHANGELOG | |
20 | index e8bf80f81baa..0bbb7835df4f 100644 | |
21 | --- a/CHANGELOG | |
22 | +++ b/CHANGELOG | |
23 | @@ -40,6 +40,9 @@ version 2.73 | |
24 | nameservers in the unsigned parts of the DNS tree | |
25 | which don't respond well to DNSSEC queries. | |
26 | ||
27 | + Add --log-queries=extra option, which makes logs easier | |
28 | + to search automatically. | |
29 | + | |
30 | ||
31 | version 2.72 | |
32 | Add ra-advrouter mode, for RFC-3775 mobile IPv6 support. | |
33 | diff --git a/man/dnsmasq.8 b/man/dnsmasq.8 | |
34 | index 4236ba307df3..227d74bd80e7 100644 | |
35 | --- a/man/dnsmasq.8 | |
36 | +++ b/man/dnsmasq.8 | |
37 | @@ -98,7 +98,10 @@ only, to stop dnsmasq daemonising in production, use | |
38 | .B -k. | |
39 | .TP | |
40 | .B \-q, --log-queries | |
41 | -Log the results of DNS queries handled by dnsmasq. Enable a full cache dump on receipt of SIGUSR1. | |
42 | +Log the results of DNS queries handled by dnsmasq. Enable a full cache dump on receipt of SIGUSR1. If the argument "extra" is supplied, ie | |
43 | +.B --log-queries=extra | |
44 | +then the log has extra information at the start of each line. | |
45 | +This consists of a serial number which ties together the log lines associated with an individual query, and the IP address of the requestor. | |
46 | .TP | |
47 | .B \-8, --log-facility=<facility> | |
48 | Set the facility to which dnsmasq will send syslog entries, this | |
49 | diff --git a/src/cache.c b/src/cache.c | |
50 | index ff1ca6f1c352..960bb7938778 100644 | |
51 | --- a/src/cache.c | |
52 | +++ b/src/cache.c | |
53 | @@ -1638,7 +1638,16 @@ void log_query(unsigned int flags, char *name, struct all_addr *addr, char *arg) | |
54 | if (strlen(name) == 0) | |
55 | name = "."; | |
56 | ||
57 | - my_syslog(LOG_INFO, "%s %s %s %s", source, name, verb, dest); | |
58 | + if (option_bool(OPT_EXTRALOG)) | |
59 | + { | |
60 | + prettyprint_addr(daemon->log_source_addr, daemon->addrbuff2); | |
61 | + if (flags & F_NOEXTRA) | |
62 | + my_syslog(LOG_INFO, "* %s %s %s %s %s", daemon->addrbuff2, source, name, verb, dest); | |
63 | + else | |
64 | + my_syslog(LOG_INFO, "%u %s %s %s %s %s", daemon->log_display_id, daemon->addrbuff2, source, name, verb, dest); | |
65 | + } | |
66 | + else | |
67 | + my_syslog(LOG_INFO, "%s %s %s %s", source, name, verb, dest); | |
68 | } | |
69 | ||
70 | ||
71 | diff --git a/src/config.h b/src/config.h | |
72 | index 145820ad2510..3b88d8193dca 100644 | |
73 | --- a/src/config.h | |
74 | +++ b/src/config.h | |
75 | @@ -17,6 +17,7 @@ | |
76 | #define FTABSIZ 150 /* max number of outstanding requests (default) */ | |
77 | #define MAX_PROCS 20 /* max no children for TCP requests */ | |
78 | #define CHILD_LIFETIME 150 /* secs 'till terminated (RFC1035 suggests > 120s) */ | |
79 | +#define TCP_MAX_QUERIES 100 /* Maximum number of queries per incoming TCP connection */ | |
80 | #define EDNS_PKTSZ 4096 /* default max EDNS.0 UDP packet from RFC5625 */ | |
81 | #define KEYBLOCK_LEN 40 /* choose to mininise fragmentation when storing DNSSEC keys */ | |
82 | #define DNSSEC_WORK 50 /* Max number of queries to validate one question */ | |
83 | diff --git a/src/dnsmasq.c b/src/dnsmasq.c | |
84 | index 5c7750d365fa..c0c0589d4ce1 100644 | |
85 | --- a/src/dnsmasq.c | |
86 | +++ b/src/dnsmasq.c | |
87 | @@ -93,6 +93,8 @@ int main (int argc, char **argv) | |
88 | daemon->packet = safe_malloc(daemon->packet_buff_sz); | |
89 | ||
90 | daemon->addrbuff = safe_malloc(ADDRSTRLEN); | |
91 | + if (option_bool(OPT_EXTRALOG)) | |
92 | + daemon->addrbuff2 = safe_malloc(ADDRSTRLEN); | |
93 | ||
94 | #ifdef HAVE_DNSSEC | |
95 | if (option_bool(OPT_DNSSEC_VALID)) | |
96 | @@ -1587,6 +1589,9 @@ static void check_dns_listeners(fd_set *set, time_t now) | |
97 | } | |
98 | } | |
99 | close(confd); | |
100 | + | |
101 | + /* The child can use up to TCP_MAX_QUERIES ids, so skip that many. */ | |
102 | + daemon->log_id += TCP_MAX_QUERIES; | |
103 | } | |
104 | #endif | |
105 | else | |
106 | diff --git a/src/dnsmasq.h b/src/dnsmasq.h | |
107 | index 2f4597294a56..4e9aea401b75 100644 | |
108 | --- a/src/dnsmasq.h | |
109 | +++ b/src/dnsmasq.h | |
110 | @@ -238,7 +238,8 @@ struct event_desc { | |
111 | #define OPT_DNSSEC_NO_SIGN 48 | |
112 | #define OPT_LOCAL_SERVICE 49 | |
113 | #define OPT_LOOP_DETECT 50 | |
114 | -#define OPT_LAST 51 | |
115 | +#define OPT_EXTRALOG 51 | |
116 | +#define OPT_LAST 52 | |
117 | ||
118 | /* extra flags for my_syslog, we use a couple of facilities since they are known | |
119 | not to occupy the same bits as priorities, no matter how syslog.h is set up. */ | |
120 | @@ -442,6 +443,7 @@ struct crec { | |
121 | #define F_NO_RR (1u<<25) | |
122 | #define F_IPSET (1u<<26) | |
123 | #define F_NSIGMATCH (1u<<27) | |
124 | +#define F_NOEXTRA (1u<<28) | |
125 | ||
126 | /* Values of uid in crecs with F_CONFIG bit set. */ | |
127 | #define SRC_INTERFACE 0 | |
128 | @@ -599,7 +601,7 @@ struct frec { | |
129 | #endif | |
130 | unsigned int iface; | |
131 | unsigned short orig_id, new_id; | |
132 | - int fd, forwardall, flags; | |
133 | + int log_id, fd, forwardall, flags; | |
134 | time_t time; | |
135 | unsigned char *hash[HASH_SIZE]; | |
136 | #ifdef HAVE_DNSSEC | |
137 | @@ -1002,6 +1004,8 @@ extern struct daemon { | |
138 | struct randfd randomsocks[RANDOM_SOCKS]; | |
139 | int v6pktinfo; | |
140 | struct addrlist *interface_addrs; /* list of all addresses/prefix lengths associated with all local interfaces */ | |
141 | + int log_id, log_display_id; /* ids of transactions for logging */ | |
142 | + union mysockaddr *log_source_addr; | |
143 | ||
144 | /* DHCP state */ | |
145 | int dhcpfd, helperfd, pxefd; | |
146 | @@ -1033,6 +1037,7 @@ extern struct daemon { | |
147 | ||
148 | /* utility string buffer, hold max sized IP address as string */ | |
149 | char *addrbuff; | |
150 | + char *addrbuff2; /* only allocated when OPT_EXTRALOG */ | |
151 | ||
152 | } *daemon; | |
153 | ||
154 | diff --git a/src/dnssec.c b/src/dnssec.c | |
155 | index 8f27677628b2..afb3dca38cb1 100644 | |
156 | --- a/src/dnssec.c | |
157 | +++ b/src/dnssec.c | |
158 | @@ -1038,7 +1038,7 @@ int dnssec_validate_by_ds(time_t now, struct dns_header *header, size_t plen, ch | |
159 | else | |
160 | { | |
161 | a.addr.keytag = keytag; | |
162 | - log_query(F_KEYTAG | F_UPSTREAM, name, &a, "DNSKEY keytag %u"); | |
163 | + log_query(F_NOEXTRA | F_KEYTAG | F_UPSTREAM, name, &a, "DNSKEY keytag %u"); | |
164 | ||
165 | recp1->addr.key.keylen = rdlen - 4; | |
166 | recp1->addr.key.keydata = key; | |
167 | @@ -1092,7 +1092,7 @@ int dnssec_validate_by_ds(time_t now, struct dns_header *header, size_t plen, ch | |
168 | return STAT_SECURE; | |
169 | } | |
170 | ||
171 | - log_query(F_UPSTREAM, name, NULL, "BOGUS DNSKEY"); | |
172 | + log_query(F_NOEXTRA | F_UPSTREAM, name, NULL, "BOGUS DNSKEY"); | |
173 | return STAT_BOGUS; | |
174 | } | |
175 | ||
176 | @@ -1136,7 +1136,7 @@ int dnssec_validate_ds(time_t now, struct dns_header *header, size_t plen, char | |
177 | ||
178 | if (val == STAT_BOGUS) | |
179 | { | |
180 | - log_query(F_UPSTREAM, name, NULL, "BOGUS DS"); | |
181 | + log_query(F_NOEXTRA | F_UPSTREAM, name, NULL, "BOGUS DS"); | |
182 | return STAT_BOGUS; | |
183 | } | |
184 | ||
185 | @@ -1201,7 +1201,7 @@ int dnssec_validate_ds(time_t now, struct dns_header *header, size_t plen, char | |
186 | ||
187 | cache_end_insert(); | |
188 | ||
189 | - log_query(F_UPSTREAM, name, NULL, nons ? "no delegation" : "no DS"); | |
190 | + log_query(F_NOEXTRA | F_UPSTREAM, name, NULL, nons ? "no delegation" : "no DS"); | |
191 | } | |
192 | ||
193 | return nons ? STAT_NO_NS : STAT_NO_DS; | |
194 | @@ -1885,7 +1885,7 @@ int dnssec_validate_reply(time_t now, struct dns_header *header, size_t plen, ch | |
195 | else | |
196 | { | |
197 | a.addr.keytag = keytag; | |
198 | - log_query(F_KEYTAG | F_UPSTREAM, name, &a, "DS keytag %u"); | |
199 | + log_query(F_NOEXTRA | F_KEYTAG | F_UPSTREAM, name, &a, "DS keytag %u"); | |
200 | crecp->addr.ds.digest = digest; | |
201 | crecp->addr.ds.keydata = key; | |
202 | crecp->addr.ds.algo = algo; | |
203 | @@ -2058,10 +2058,10 @@ size_t dnssec_generate_query(struct dns_header *header, char *end, char *name, i | |
204 | char *types = querystr("dnssec-query", type); | |
205 | ||
206 | if (addr->sa.sa_family == AF_INET) | |
207 | - log_query(F_DNSSEC | F_IPV4, name, (struct all_addr *)&addr->in.sin_addr, types); | |
208 | + log_query(F_NOEXTRA | F_DNSSEC | F_IPV4, name, (struct all_addr *)&addr->in.sin_addr, types); | |
209 | #ifdef HAVE_IPV6 | |
210 | else | |
211 | - log_query(F_DNSSEC | F_IPV6, name, (struct all_addr *)&addr->in6.sin6_addr, types); | |
212 | + log_query(F_NOEXTRA | F_DNSSEC | F_IPV6, name, (struct all_addr *)&addr->in6.sin6_addr, types); | |
213 | #endif | |
214 | ||
215 | header->qdcount = htons(1); | |
216 | diff --git a/src/forward.c b/src/forward.c | |
217 | index 55f583383bc6..713a64c0fa58 100644 | |
218 | --- a/src/forward.c | |
219 | +++ b/src/forward.c | |
220 | @@ -279,10 +279,10 @@ static int forward_query(int udpfd, union mysockaddr *udpaddr, | |
221 | plen = forward->stash_len; | |
222 | ||
223 | if (forward->sentto->addr.sa.sa_family == AF_INET) | |
224 | - log_query(F_DNSSEC | F_IPV4, "retry", (struct all_addr *)&forward->sentto->addr.in.sin_addr, "dnssec"); | |
225 | + log_query(F_NOEXTRA | F_DNSSEC | F_IPV4, "retry", (struct all_addr *)&forward->sentto->addr.in.sin_addr, "dnssec"); | |
226 | #ifdef HAVE_IPV6 | |
227 | else | |
228 | - log_query(F_DNSSEC | F_IPV6, "retry", (struct all_addr *)&forward->sentto->addr.in6.sin6_addr, "dnssec"); | |
229 | + log_query(F_NOEXTRA | F_DNSSEC | F_IPV6, "retry", (struct all_addr *)&forward->sentto->addr.in6.sin6_addr, "dnssec"); | |
230 | #endif | |
231 | ||
232 | if (forward->sentto->sfd) | |
233 | @@ -389,6 +389,9 @@ static int forward_query(int udpfd, union mysockaddr *udpaddr, | |
234 | struct server *firstsentto = start; | |
235 | int forwarded = 0; | |
236 | ||
237 | + /* If a query is retried, use the log_id for the retry when logging the answer. */ | |
238 | + forward->log_id = daemon->log_id; | |
239 | + | |
240 | if (option_bool(OPT_ADD_MAC)) | |
241 | plen = add_mac(header, plen, ((char *) header) + daemon->packet_buff_sz, &forward->source); | |
242 | ||
243 | @@ -725,6 +728,11 @@ void reply_query(int fd, int family, time_t now) | |
244 | if (!(forward = lookup_frec(ntohs(header->id), hash))) | |
245 | return; | |
246 | ||
247 | + /* log_query gets called indirectly all over the place, so | |
248 | + pass these in global variables - sorry. */ | |
249 | + daemon->log_display_id = forward->log_id; | |
250 | + daemon->log_source_addr = &forward->source; | |
251 | + | |
252 | if (daemon->ignore_addr && RCODE(header) == NOERROR && | |
253 | check_for_ignored_address(header, n, daemon->ignore_addr)) | |
254 | return; | |
255 | @@ -1258,6 +1266,11 @@ void receive_query(struct listener *listen, time_t now) | |
256 | dst_addr_4.s_addr = 0; | |
257 | } | |
258 | } | |
259 | + | |
260 | + /* log_query gets called indirectly all over the place, so | |
261 | + pass these in global variables - sorry. */ | |
262 | + daemon->log_display_id = ++daemon->log_id; | |
263 | + daemon->log_source_addr = &source_addr; | |
264 | ||
265 | if (extract_request(header, (size_t)n, daemon->namebuff, &type)) | |
266 | { | |
267 | @@ -1675,7 +1688,8 @@ unsigned char *tcp_request(int confd, time_t now, | |
268 | struct in_addr dst_addr_4; | |
269 | union mysockaddr peer_addr; | |
270 | socklen_t peer_len = sizeof(union mysockaddr); | |
271 | - | |
272 | + int query_count = 0; | |
273 | + | |
274 | if (getpeername(confd, (struct sockaddr *)&peer_addr, &peer_len) == -1) | |
275 | return packet; | |
276 | ||
277 | @@ -1712,7 +1726,8 @@ unsigned char *tcp_request(int confd, time_t now, | |
278 | ||
279 | while (1) | |
280 | { | |
281 | - if (!packet || | |
282 | + if (query_count == TCP_MAX_QUERIES || | |
283 | + !packet || | |
284 | !read_write(confd, &c1, 1, 1) || !read_write(confd, &c2, 1, 1) || | |
285 | !(size = c1 << 8 | c2) || | |
286 | !read_write(confd, payload, size, 1)) | |
287 | @@ -1721,6 +1736,13 @@ unsigned char *tcp_request(int confd, time_t now, | |
288 | if (size < (int)sizeof(struct dns_header)) | |
289 | continue; | |
290 | ||
291 | + query_count++; | |
292 | + | |
293 | + /* log_query gets called indirectly all over the place, so | |
294 | + pass these in global variables - sorry. */ | |
295 | + daemon->log_display_id = ++daemon->log_id; | |
296 | + daemon->log_source_addr = &peer_addr; | |
297 | + | |
298 | check_subnet = 0; | |
299 | ||
300 | /* save state of "cd" flag in query */ | |
301 | diff --git a/src/option.c b/src/option.c | |
302 | index 907d0cf88de9..b7372be0a090 100644 | |
303 | --- a/src/option.c | |
304 | +++ b/src/option.c | |
305 | @@ -149,6 +149,7 @@ struct myoption { | |
306 | #define LOPT_LOOP_DETECT 337 | |
307 | #define LOPT_IGNORE_ADDR 338 | |
308 | ||
309 | + | |
310 | #ifdef HAVE_GETOPT_LONG | |
311 | static const struct option opts[] = | |
312 | #else | |
313 | @@ -160,7 +161,7 @@ static const struct myoption opts[] = | |
314 | { "no-poll", 0, 0, 'n' }, | |
315 | { "help", 0, 0, 'w' }, | |
316 | { "no-daemon", 0, 0, 'd' }, | |
317 | - { "log-queries", 0, 0, 'q' }, | |
318 | + { "log-queries", 2, 0, 'q' }, | |
319 | { "user", 2, 0, 'u' }, | |
320 | { "group", 2, 0, 'g' }, | |
321 | { "resolv-file", 2, 0, 'r' }, | |
322 | @@ -357,7 +358,7 @@ static struct { | |
323 | { LOPT_FORCE, ARG_DUP, "<optspec>", gettext_noop("DHCP option sent even if the client does not request it."), NULL}, | |
324 | { 'p', ARG_ONE, "<integer>", gettext_noop("Specify port to listen for DNS requests on (defaults to 53)."), NULL }, | |
325 | { 'P', ARG_ONE, "<integer>", gettext_noop("Maximum supported UDP packet size for EDNS.0 (defaults to %s)."), "*" }, | |
326 | - { 'q', OPT_LOG, NULL, gettext_noop("Log DNS queries."), NULL }, | |
327 | + { 'q', ARG_DUP, NULL, gettext_noop("Log DNS queries."), NULL }, | |
328 | { 'Q', ARG_ONE, "<integer>", gettext_noop("Force the originating port for upstream DNS queries."), NULL }, | |
329 | { 'R', OPT_NO_RESOLV, NULL, gettext_noop("Do NOT read resolv.conf."), NULL }, | |
330 | { 'r', ARG_DUP, "<path>", gettext_noop("Specify path to resolv.conf (defaults to %s)."), RESOLVFILE }, | |
331 | @@ -2421,6 +2422,12 @@ static int one_opt(int option, char *arg, char *errstr, char *gen_err, int comma | |
332 | ret_err(gen_err); | |
333 | break; | |
334 | ||
335 | + case 'q': /* --log-queries */ | |
336 | + set_option_bool(OPT_LOG); | |
337 | + if (arg && strcmp(arg, "extra") == 0) | |
338 | + set_option_bool(OPT_EXTRALOG); | |
339 | + break; | |
340 | + | |
341 | case LOPT_MAX_LOGS: /* --log-async */ | |
342 | daemon->max_logs = LOG_MAX; /* default */ | |
343 | if (arg && !atoi_check(arg, &daemon->max_logs)) | |
344 | -- | |
345 | 2.1.0 | |
346 |