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