xref: /illumos-gate/usr/src/cmd/fs.d/nfs/nfslog/process_buffer.c (revision 20a7641f9918de8574b8b3b47dbe35c4bfc78df1)
1 /*
2  * CDDL HEADER START
3  *
4  * The contents of this file are subject to the terms of the
5  * Common Development and Distribution License (the "License").
6  * You may not use this file except in compliance with the License.
7  *
8  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
9  * or http://www.opensolaris.org/os/licensing.
10  * See the License for the specific language governing permissions
11  * and limitations under the License.
12  *
13  * When distributing Covered Code, include this CDDL HEADER in each
14  * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
15  * If applicable, add the following below this CDDL HEADER, with the
16  * fields enclosed by brackets "[]" replaced with your own identifying
17  * information: Portions Copyright [yyyy] [name of copyright owner]
18  *
19  * CDDL HEADER END
20  */
21 /*
22  * Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
23  * Use is subject to license terms.
24  */
25 
26 #include <strings.h>
27 #include <string.h>
28 #include <syslog.h>
29 #include <locale.h>
30 #include <nfs/nfs.h>
31 #include <nfs/export.h>
32 #include <nfs/nfssys.h>
33 #include <nfs/nfs_log.h>
34 #include <sys/types.h>
35 #include <sys/stat.h>
36 #include <stdio.h>
37 #include <errno.h>
38 #include <assert.h>
39 #include <stdlib.h>
40 #include <unistd.h>
41 #include <nfs/nfs_log.h>
42 #include "../lib/nfslog_config.h"
43 #include "buffer_list.h"
44 #include "nfslogd.h"
45 
46 extern int _nfssys(int, void *);
47 
48 /*
49  * simple list used to keep track of bad tag messages syslogged.
50  */
51 struct nfs_log_list {
52 	char *l_name;
53 	struct nfs_log_list *l_next;
54 };
55 
56 static void badtag_notify(char *tag);
57 static struct nfs_log_list *badtag_list = NULL;
58 
59 static void cleanup_elf_state(nfsl_config_t *);
60 static void cleanup_trans_state(nfsl_config_t *);
61 
62 /*
63  * Read the contents of the 'bufferpath', process them and store the
64  * user-readable log in 'elfpath', updating the 'fhpath' filehandle
65  * table.
66  * The contents of the configuration list (*config_list) may be
67  * modified if the configuration file has been updated and we can not
68  * find the configuration entry in the currently loaded list.
69  *
70  * Returns 0 on success and sets *buffer_processed to 1.
71  *	   non zero error on failure and *buffer_processed set to 0.
72  */
73 int
74 process_buffer(
75 	struct buffer_ent *bep,
76 	nfsl_config_t **config_list,
77 	int min_size,
78 	int idle_time,
79 	int *buffer_processed)
80 {
81 	struct stat st;
82 	struct nfsl_flush_args nfa;
83 	struct nfslog_buf *lbp = NULL;
84 	struct nfslog_lr *lrp;
85 	char *path1 = NULL;
86 	char *path2 = NULL;
87 	char *buffer_inprog = NULL;
88 	int buffer_inprog_len;
89 	int error = 0;
90 	nfsl_config_t *ncp = NULL, *last_good_ncp;
91 	char *bufferpath = bep->be_name;
92 	char *tag;
93 	boolean_t elf_checked = B_FALSE;
94 	boolean_t trans_checked = B_FALSE;
95 
96 	assert(buffer_processed != NULL);
97 	assert(bufferpath != NULL);
98 
99 	if (stat(bufferpath, &st) == -1) {
100 		error = errno;
101 		if (error == ENOENT) {
102 			error = 0;
103 			buffer_inprog_len = strlen(bufferpath) +
104 			    strlen(LOG_INPROG_STRING) + 1;
105 			buffer_inprog = (char *)malloc(buffer_inprog_len);
106 			if (buffer_inprog == NULL) {
107 				syslog(LOG_ERR, gettext(
108 				    "process_buffer: malloc failed"));
109 				return (ENOMEM);
110 			}
111 			(void) sprintf(buffer_inprog, "%s%s", bufferpath,
112 			    LOG_INPROG_STRING);
113 
114 			if (stat(buffer_inprog, &st) == -1) {
115 				error = errno;
116 				if (bep->be_error != error) {
117 					syslog(LOG_ERR, gettext(
118 					    "Can not stat %s: %s"),
119 					    buffer_inprog, strerror(error));
120 				}
121 				free(buffer_inprog);
122 				return (error);
123 			}
124 
125 			free(buffer_inprog);
126 
127 			/*
128 			 * Does the buffer in progress meet our minimum
129 			 * processing requirements? or has it been around
130 			 * longer than we're willing to wait for more
131 			 * data to be logged?
132 			 */
133 			if ((st.st_size < min_size) &&
134 			    ((time(0) - bep->be_lastprocessed) < idle_time)) {
135 				/*
136 				 * The buffer does not meet the minimum
137 				 * size processing requirements, and it has not
138 				 * been around longer than we're willing to
139 				 * wait for more data collection.
140 				 * We return now without processing it.
141 				 */
142 				return (0);
143 			}
144 
145 			/*
146 			 * Issue the LOG_FLUSH system call to flush the
147 			 * buffer and process it.
148 			 */
149 			(void) memset((void *)&nfa, 0, sizeof (nfa));
150 			nfa.version = NFSL_FLUSH_ARGS_VERS;
151 			nfa.directive = NFSL_RENAME | NFSL_SYNC;
152 			nfa.buff = bufferpath;
153 			nfa.buff_len = strlen(bufferpath) + 1;
154 
155 			if (_nfssys(LOG_FLUSH, &nfa) < 0) {
156 				error = errno;
157 				if (bep->be_error != error) {
158 					syslog(LOG_ERR, gettext(
159 					    "_nfssys(%s) failed: %s"),
160 					    nfa.buff, strerror(error));
161 				}
162 				return (error);
163 			}
164 		} else {
165 			if (bep->be_error != error) {
166 				syslog(LOG_ERR, gettext("Can not stat %s: %s"),
167 				    bufferpath, strerror(error));
168 			}
169 			return (error);
170 		}
171 	}
172 
173 	/*
174 	 * Open and lock input buffer.
175 	 * Passes in the value of the last error so that it will not
176 	 * print it again if it is still hitting the same error condition.
177 	 */
178 	error = bep->be_error;
179 	if ((lbp = nfslog_open_buf(bufferpath, &error)) == NULL)
180 		goto done;
181 
182 	if ((ncp = last_good_ncp =
183 	    nfsl_findconfig(*config_list, "global", &error)) == NULL) {
184 		assert(error != 0);
185 		nfsl_freeconfig_list(config_list);
186 		if (error != bep->be_error) {
187 			syslog(LOG_ERR, gettext(
188 			    "Could not search config list: %s"),
189 			    strerror(error));
190 		}
191 		goto done;
192 	}
193 
194 	assert(error == 0);
195 	while ((lrp = nfslog_get_logrecord(lbp)) != NULL && keep_running) {
196 
197 		if (*buffer_processed == 0)
198 			(*buffer_processed)++;
199 
200 		/*
201 		 * Get the matching config entry.
202 		 */
203 		tag = lrp->log_record.re_tag;
204 		if (strcmp(tag, last_good_ncp->nc_name) != 0) {
205 			ncp = nfsl_findconfig(*config_list, tag, &error);
206 			if (error) {
207 				if (error != bep->be_error) {
208 					syslog(LOG_ERR, gettext(
209 					    "Could not search config list: %s"),
210 					    strerror(error));
211 				}
212 				nfsl_freeconfig_list(config_list);
213 				goto done;
214 			}
215 			if (ncp == NULL) {
216 				badtag_notify(tag);
217 				ncp = last_good_ncp;
218 				goto skip;
219 			}
220 			last_good_ncp = ncp;
221 		}
222 
223 		if (ncp->nc_flags & NC_UPDATED) {
224 			/*
225 			 * The location of the log files may have changed,
226 			 * we need to close transactions and invalidate
227 			 * cookies so that the log files can be reopened
228 			 * further down.
229 			 */
230 			cleanup_elf_state(ncp);
231 			cleanup_trans_state(ncp);
232 
233 			ncp->nc_flags &= ~NC_UPDATED;
234 
235 			/*
236 			 * Force cookies to be recreated if necessary.
237 			 */
238 			elf_checked = trans_checked = B_FALSE;
239 		}
240 
241 		/*
242 		 * Open output files.
243 		 */
244 		if (ncp->nc_rpclogpath != NULL) {
245 			/*
246 			 * Log rpc requests in W3C-ELF format.
247 			 */
248 			if (!elf_checked && ncp->nc_elfcookie != NULL) {
249 				/*
250 				 * Make sure file still exists.
251 				 * Do this once per buffer.
252 				 */
253 				if (stat(ncp->nc_rpclogpath, &st) == -1 &&
254 				    errno == ENOENT) {
255 					/*
256 					 * The open rpclogfile has been
257 					 * deleted.  Get new one below.
258 					 */
259 					cleanup_elf_state(ncp);
260 				}
261 				elf_checked = B_TRUE;
262 			}
263 			if (ncp->nc_elfcookie == NULL) {
264 				error = bep->be_error;
265 				ncp->nc_elfcookie = nfslog_open_elf_file(
266 				    ncp->nc_rpclogpath, &lbp->bh, &error);
267 				if (ncp->nc_elfcookie == NULL) {
268 					bep->be_error = error;
269 					goto done;
270 				}
271 			}
272 		}
273 
274 		if (ncp->nc_logpath != NULL) {
275 			/*
276 			 * Log rpc reqs in trans/ftp format.
277 			 */
278 			if (!trans_checked && ncp->nc_transcookie != NULL) {
279 				/*
280 				 * Do this once per buffer.
281 				 */
282 				if (stat(ncp->nc_logpath, &st) == -1 &&
283 				    errno == ENOENT) {
284 					/*
285 					 * The open transaction file has been
286 					 * deleted. Close pending transaction
287 					 * work. A new transaction log will be
288 					 * opened by nfslog_open_trans_file()
289 					 * below.
290 					 */
291 					cleanup_trans_state(ncp);
292 				}
293 				trans_checked = B_TRUE;
294 			}
295 			if (ncp->nc_transcookie == NULL) {
296 				int transtolog;
297 
298 				transtolog =
299 				    (ncp->nc_logformat == TRANSLOG_BASIC) ?
300 				    TRANSTOLOG_OPER_READWRITE : TRANSTOLOG_ALL;
301 				error = bep->be_error;
302 				ncp->nc_transcookie = nfslog_open_trans_file(
303 				    ncp->nc_logpath, ncp->nc_logformat,
304 				    transtolog, &error);
305 				if (ncp->nc_transcookie == NULL) {
306 					bep->be_error = error;
307 					goto done;
308 				}
309 			}
310 		}
311 
312 		assert(ncp->nc_fhpath != NULL);
313 
314 		if (nfslog_process_fh_rec(lrp, ncp->nc_fhpath, &path1, &path2,
315 		    ncp->nc_elfcookie != NULL)) {
316 			/*
317 			 * Make sure there is room.
318 			 */
319 			if (ncp->nc_elfcookie != NULL) {
320 				(void) nfslog_process_elf_rec(ncp->nc_elfcookie,
321 				    &lrp->log_record, path1, path2);
322 			}
323 
324 			if (ncp->nc_transcookie != NULL) {
325 				(void) nfslog_process_trans_rec(
326 				    ncp->nc_transcookie,
327 				    &lrp->log_record, ncp->nc_fhpath,
328 				    path1, path2);
329 			}
330 		}
331 
332 skip:		if (path1 != NULL)
333 			free(path1);
334 		if (path2 != NULL)
335 			free(path2);
336 
337 		path1 = path2 = NULL;
338 		nfslog_free_logrecord(lrp, TRUE);
339 	} /* while */
340 
341 	if (!error && keep_running) {
342 		/*
343 		 * Keep track of when this buffer was last processed.
344 		 */
345 		bep->be_lastprocessed = time(0);
346 
347 		if (test && *buffer_processed != 0) {
348 			/*
349 			 * Save the buffer for future debugging. We do this
350 			 * by following the log cycling policy, with a maximum
351 			 * of 'max_logs_preserve' to save.
352 			 */
353 			if (cycle_log(bufferpath, max_logs_preserve)) {
354 				syslog(LOG_ERR, gettext(
355 				    "could not save copy of buffer \"%s\""),
356 				    bufferpath);
357 			}
358 		} else {
359 			/*
360 			 * Remove buffer since it has been processed.
361 			 */
362 			if (unlink(bufferpath)) {
363 				error = errno;
364 				syslog(LOG_ERR, gettext(
365 				    "could not unlink %s: %s"),
366 				    bufferpath, strerror(error));
367 				/*
368 				 * Buffer was processed correctly.
369 				 */
370 				error = 0;
371 			}
372 		}
373 	}
374 
375 done:
376 	if (lbp != NULL)
377 		nfslog_close_buf(lbp, quick_cleaning);
378 	if (ncp && !quick_cleaning)
379 		cleanup_elf_state(ncp);
380 
381 	return (error);
382 }
383 
384 static void
385 cleanup_elf_state(nfsl_config_t *ncp)
386 {
387 	if (ncp->nc_elfcookie != NULL) {
388 		nfslog_close_elf_file(&ncp->nc_elfcookie);
389 		assert(ncp->nc_elfcookie == NULL);
390 	}
391 }
392 
393 static void
394 cleanup_trans_state(nfsl_config_t *ncp)
395 {
396 	if (ncp->nc_transcookie != NULL) {
397 		nfslog_close_transactions(&ncp->nc_transcookie);
398 		assert(ncp->nc_transcookie == NULL);
399 	}
400 }
401 
402 /*
403  * Searches the list of previously seen bad tags. Note that this
404  * list is never pruned. This should not be a problem since the
405  * list of bad tags should be fairl small. New entries are inserted
406  * at the beginning of the list assuming it will be accessed more
407  * frequently since we have just seen it.
408  */
409 static void
410 badtag_notify(char *tag)
411 {
412 	struct nfs_log_list *lp, *p;
413 	int error;
414 
415 	for (p = badtag_list; p != NULL; p = p->l_next) {
416 		if (strcmp(tag, p->l_name) == 0) {
417 			/*
418 			 * We've seen this before, nothing to do.
419 			 */
420 			return;
421 		}
422 	}
423 
424 	/*
425 	 * Not on the list, add it.
426 	 */
427 	syslog(LOG_ERR, gettext("tag \"%s\" not found in %s - "
428 	    "ignoring records referencing such tag."),
429 	    tag, NFSL_CONFIG_FILE_PATH);
430 
431 	if ((lp = (struct nfs_log_list *)malloc(sizeof (*lp))) != NULL) {
432 		if ((lp->l_name = strdup(tag)) != NULL) {
433 			lp->l_next = badtag_list;
434 			badtag_list = lp;
435 			return;		/* done */
436 		}
437 	}
438 
439 	if (lp->l_name != NULL)
440 		free(lp->l_name);
441 	if (lp)
442 		free(lp);
443 	error = errno;
444 	syslog(LOG_ERR, gettext(
445 	    "Cannot add \"%s\" to bad tag list: %s"), tag, strerror(error));
446 }
447