xref: /illumos-gate/usr/src/uts/common/fs/zfs/spa_history.c (revision cd1c8b85eb30b568e9816221430c479ace7a559d)
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 /*
23  * Copyright (c) 2006, 2010, Oracle and/or its affiliates. All rights reserved.
24  * Copyright (c) 2012 by Delphix. All rights reserved.
25  */
26 
27 #include <sys/spa.h>
28 #include <sys/spa_impl.h>
29 #include <sys/zap.h>
30 #include <sys/dsl_synctask.h>
31 #include <sys/dmu_tx.h>
32 #include <sys/dmu_objset.h>
33 #include <sys/dsl_dataset.h>
34 #include <sys/dsl_dir.h>
35 #include <sys/utsname.h>
36 #include <sys/cmn_err.h>
37 #include <sys/sunddi.h>
38 #include <sys/cred.h>
39 #include "zfs_comutil.h"
40 #ifdef _KERNEL
41 #include <sys/zone.h>
42 #endif
43 
44 /*
45  * Routines to manage the on-disk history log.
46  *
47  * The history log is stored as a dmu object containing
48  * <packed record length, record nvlist> tuples.
49  *
50  * Where "record nvlist" is a nvlist containing uint64_ts and strings, and
51  * "packed record length" is the packed length of the "record nvlist" stored
52  * as a little endian uint64_t.
53  *
54  * The log is implemented as a ring buffer, though the original creation
55  * of the pool ('zpool create') is never overwritten.
56  *
57  * The history log is tracked as object 'spa_t::spa_history'.  The bonus buffer
58  * of 'spa_history' stores the offsets for logging/retrieving history as
59  * 'spa_history_phys_t'.  'sh_pool_create_len' is the ending offset in bytes of
60  * where the 'zpool create' record is stored.  This allows us to never
61  * overwrite the original creation of the pool.  'sh_phys_max_off' is the
62  * physical ending offset in bytes of the log.  This tells you the length of
63  * the buffer. 'sh_eof' is the logical EOF (in bytes).  Whenever a record
64  * is added, 'sh_eof' is incremented by the the size of the record.
65  * 'sh_eof' is never decremented.  'sh_bof' is the logical BOF (in bytes).
66  * This is where the consumer should start reading from after reading in
67  * the 'zpool create' portion of the log.
68  *
69  * 'sh_records_lost' keeps track of how many records have been overwritten
70  * and permanently lost.
71  */
72 
73 /* convert a logical offset to physical */
74 static uint64_t
75 spa_history_log_to_phys(uint64_t log_off, spa_history_phys_t *shpp)
76 {
77 	uint64_t phys_len;
78 
79 	phys_len = shpp->sh_phys_max_off - shpp->sh_pool_create_len;
80 	return ((log_off - shpp->sh_pool_create_len) % phys_len
81 	    + shpp->sh_pool_create_len);
82 }
83 
84 void
85 spa_history_create_obj(spa_t *spa, dmu_tx_t *tx)
86 {
87 	dmu_buf_t *dbp;
88 	spa_history_phys_t *shpp;
89 	objset_t *mos = spa->spa_meta_objset;
90 
91 	ASSERT(spa->spa_history == 0);
92 	spa->spa_history = dmu_object_alloc(mos, DMU_OT_SPA_HISTORY,
93 	    SPA_MAXBLOCKSIZE, DMU_OT_SPA_HISTORY_OFFSETS,
94 	    sizeof (spa_history_phys_t), tx);
95 
96 	VERIFY(zap_add(mos, DMU_POOL_DIRECTORY_OBJECT,
97 	    DMU_POOL_HISTORY, sizeof (uint64_t), 1,
98 	    &spa->spa_history, tx) == 0);
99 
100 	VERIFY(0 == dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp));
101 	ASSERT(dbp->db_size >= sizeof (spa_history_phys_t));
102 
103 	shpp = dbp->db_data;
104 	dmu_buf_will_dirty(dbp, tx);
105 
106 	/*
107 	 * Figure out maximum size of history log.  We set it at
108 	 * 0.1% of pool size, with a max of 1G and min of 128KB.
109 	 */
110 	shpp->sh_phys_max_off =
111 	    metaslab_class_get_dspace(spa_normal_class(spa)) / 1000;
112 	shpp->sh_phys_max_off = MIN(shpp->sh_phys_max_off, 1<<30);
113 	shpp->sh_phys_max_off = MAX(shpp->sh_phys_max_off, 128<<10);
114 
115 	dmu_buf_rele(dbp, FTAG);
116 }
117 
118 /*
119  * Change 'sh_bof' to the beginning of the next record.
120  */
121 static int
122 spa_history_advance_bof(spa_t *spa, spa_history_phys_t *shpp)
123 {
124 	objset_t *mos = spa->spa_meta_objset;
125 	uint64_t firstread, reclen, phys_bof;
126 	char buf[sizeof (reclen)];
127 	int err;
128 
129 	phys_bof = spa_history_log_to_phys(shpp->sh_bof, shpp);
130 	firstread = MIN(sizeof (reclen), shpp->sh_phys_max_off - phys_bof);
131 
132 	if ((err = dmu_read(mos, spa->spa_history, phys_bof, firstread,
133 	    buf, DMU_READ_PREFETCH)) != 0)
134 		return (err);
135 	if (firstread != sizeof (reclen)) {
136 		if ((err = dmu_read(mos, spa->spa_history,
137 		    shpp->sh_pool_create_len, sizeof (reclen) - firstread,
138 		    buf + firstread, DMU_READ_PREFETCH)) != 0)
139 			return (err);
140 	}
141 
142 	reclen = LE_64(*((uint64_t *)buf));
143 	shpp->sh_bof += reclen + sizeof (reclen);
144 	shpp->sh_records_lost++;
145 	return (0);
146 }
147 
148 static int
149 spa_history_write(spa_t *spa, void *buf, uint64_t len, spa_history_phys_t *shpp,
150     dmu_tx_t *tx)
151 {
152 	uint64_t firstwrite, phys_eof;
153 	objset_t *mos = spa->spa_meta_objset;
154 	int err;
155 
156 	ASSERT(MUTEX_HELD(&spa->spa_history_lock));
157 
158 	/* see if we need to reset logical BOF */
159 	while (shpp->sh_phys_max_off - shpp->sh_pool_create_len -
160 	    (shpp->sh_eof - shpp->sh_bof) <= len) {
161 		if ((err = spa_history_advance_bof(spa, shpp)) != 0) {
162 			return (err);
163 		}
164 	}
165 
166 	phys_eof = spa_history_log_to_phys(shpp->sh_eof, shpp);
167 	firstwrite = MIN(len, shpp->sh_phys_max_off - phys_eof);
168 	shpp->sh_eof += len;
169 	dmu_write(mos, spa->spa_history, phys_eof, firstwrite, buf, tx);
170 
171 	len -= firstwrite;
172 	if (len > 0) {
173 		/* write out the rest at the beginning of physical file */
174 		dmu_write(mos, spa->spa_history, shpp->sh_pool_create_len,
175 		    len, (char *)buf + firstwrite, tx);
176 	}
177 
178 	return (0);
179 }
180 
181 static char *
182 spa_history_zone(void)
183 {
184 #ifdef _KERNEL
185 	if (INGLOBALZONE(curproc))
186 		return (NULL);
187 	return (curproc->p_zone->zone_name);
188 #else
189 	return (NULL);
190 #endif
191 }
192 
193 /*
194  * Write out a history event.
195  */
196 /*ARGSUSED*/
197 static void
198 spa_history_log_sync(void *arg1, void *arg2, dmu_tx_t *tx)
199 {
200 	spa_t		*spa = arg1;
201 	nvlist_t	*nvl = arg2;
202 	objset_t	*mos = spa->spa_meta_objset;
203 	dmu_buf_t	*dbp;
204 	spa_history_phys_t *shpp;
205 	size_t		reclen;
206 	uint64_t	le_len;
207 	char		*record_packed = NULL;
208 	int		ret;
209 
210 	/*
211 	 * If we have an older pool that doesn't have a command
212 	 * history object, create it now.
213 	 */
214 	mutex_enter(&spa->spa_history_lock);
215 	if (!spa->spa_history)
216 		spa_history_create_obj(spa, tx);
217 	mutex_exit(&spa->spa_history_lock);
218 
219 	/*
220 	 * Get the offset of where we need to write via the bonus buffer.
221 	 * Update the offset when the write completes.
222 	 */
223 	VERIFY(0 == dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp));
224 	shpp = dbp->db_data;
225 
226 	dmu_buf_will_dirty(dbp, tx);
227 
228 #ifdef ZFS_DEBUG
229 	{
230 		dmu_object_info_t doi;
231 		dmu_object_info_from_db(dbp, &doi);
232 		ASSERT3U(doi.doi_bonus_type, ==, DMU_OT_SPA_HISTORY_OFFSETS);
233 	}
234 #endif
235 
236 	fnvlist_add_uint64(nvl, ZPOOL_HIST_TIME, gethrestime_sec());
237 #ifdef _KERNEL
238 	fnvlist_add_string(nvl, ZPOOL_HIST_HOST, utsname.nodename);
239 #endif
240 	if (nvlist_exists(nvl, ZPOOL_HIST_CMD)) {
241 		zfs_dbgmsg("command: %s",
242 		    fnvlist_lookup_string(nvl, ZPOOL_HIST_CMD));
243 	} else if (nvlist_exists(nvl, ZPOOL_HIST_INT_NAME)) {
244 		if (nvlist_exists(nvl, ZPOOL_HIST_DSNAME)) {
245 			zfs_dbgmsg("txg %lld %s %s (id %llu) %s",
246 			    fnvlist_lookup_uint64(nvl, ZPOOL_HIST_TXG),
247 			    fnvlist_lookup_string(nvl, ZPOOL_HIST_INT_NAME),
248 			    fnvlist_lookup_string(nvl, ZPOOL_HIST_DSNAME),
249 			    fnvlist_lookup_uint64(nvl, ZPOOL_HIST_DSID),
250 			    fnvlist_lookup_string(nvl, ZPOOL_HIST_INT_STR));
251 		} else {
252 			zfs_dbgmsg("txg %lld %s %s",
253 			    fnvlist_lookup_uint64(nvl, ZPOOL_HIST_TXG),
254 			    fnvlist_lookup_string(nvl, ZPOOL_HIST_INT_NAME),
255 			    fnvlist_lookup_string(nvl, ZPOOL_HIST_INT_STR));
256 		}
257 	} else if (nvlist_exists(nvl, ZPOOL_HIST_IOCTL)) {
258 		zfs_dbgmsg("ioctl %s",
259 		    fnvlist_lookup_string(nvl, ZPOOL_HIST_IOCTL));
260 	}
261 
262 	record_packed = fnvlist_pack(nvl, &reclen);
263 
264 	mutex_enter(&spa->spa_history_lock);
265 
266 	/* write out the packed length as little endian */
267 	le_len = LE_64((uint64_t)reclen);
268 	ret = spa_history_write(spa, &le_len, sizeof (le_len), shpp, tx);
269 	if (!ret)
270 		ret = spa_history_write(spa, record_packed, reclen, shpp, tx);
271 
272 	/* The first command is the create, which we keep forever */
273 	if (ret == 0 && shpp->sh_pool_create_len == 0 &&
274 	    nvlist_exists(nvl, ZPOOL_HIST_CMD)) {
275 		shpp->sh_pool_create_len = shpp->sh_bof = shpp->sh_eof;
276 	}
277 
278 	mutex_exit(&spa->spa_history_lock);
279 	fnvlist_pack_free(record_packed, reclen);
280 	dmu_buf_rele(dbp, FTAG);
281 	fnvlist_free(nvl);
282 }
283 
284 /*
285  * Write out a history event.
286  */
287 int
288 spa_history_log(spa_t *spa, const char *msg)
289 {
290 	int err;
291 	nvlist_t *nvl = fnvlist_alloc();
292 
293 	fnvlist_add_string(nvl, ZPOOL_HIST_CMD, msg);
294 	err = spa_history_log_nvl(spa, nvl);
295 	fnvlist_free(nvl);
296 	return (err);
297 }
298 
299 int
300 spa_history_log_nvl(spa_t *spa, nvlist_t *nvl)
301 {
302 	int err = 0;
303 	dmu_tx_t *tx;
304 	nvlist_t *nvarg;
305 
306 	if (spa_version(spa) < SPA_VERSION_ZPOOL_HISTORY || !spa_writeable(spa))
307 		return (EINVAL);
308 
309 	tx = dmu_tx_create_dd(spa_get_dsl(spa)->dp_mos_dir);
310 	err = dmu_tx_assign(tx, TXG_WAIT);
311 	if (err) {
312 		dmu_tx_abort(tx);
313 		return (err);
314 	}
315 
316 	nvarg = fnvlist_dup(nvl);
317 	if (spa_history_zone() != NULL) {
318 		fnvlist_add_string(nvarg, ZPOOL_HIST_ZONE,
319 		    spa_history_zone());
320 	}
321 	fnvlist_add_uint64(nvarg, ZPOOL_HIST_WHO, crgetruid(CRED()));
322 
323 	/* Kick this off asynchronously; errors are ignored. */
324 	dsl_sync_task_do_nowait(spa_get_dsl(spa), NULL,
325 	    spa_history_log_sync, spa, nvarg, 0, tx);
326 	dmu_tx_commit(tx);
327 
328 	/* spa_history_log_sync will free nvl */
329 	return (err);
330 
331 }
332 
333 /*
334  * Read out the command history.
335  */
336 int
337 spa_history_get(spa_t *spa, uint64_t *offp, uint64_t *len, char *buf)
338 {
339 	objset_t *mos = spa->spa_meta_objset;
340 	dmu_buf_t *dbp;
341 	uint64_t read_len, phys_read_off, phys_eof;
342 	uint64_t leftover = 0;
343 	spa_history_phys_t *shpp;
344 	int err;
345 
346 	/*
347 	 * If the command history doesn't exist (older pool),
348 	 * that's ok, just return ENOENT.
349 	 */
350 	if (!spa->spa_history)
351 		return (ENOENT);
352 
353 	/*
354 	 * The history is logged asynchronously, so when they request
355 	 * the first chunk of history, make sure everything has been
356 	 * synced to disk so that we get it.
357 	 */
358 	if (*offp == 0 && spa_writeable(spa))
359 		txg_wait_synced(spa_get_dsl(spa), 0);
360 
361 	if ((err = dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp)) != 0)
362 		return (err);
363 	shpp = dbp->db_data;
364 
365 #ifdef ZFS_DEBUG
366 	{
367 		dmu_object_info_t doi;
368 		dmu_object_info_from_db(dbp, &doi);
369 		ASSERT3U(doi.doi_bonus_type, ==, DMU_OT_SPA_HISTORY_OFFSETS);
370 	}
371 #endif
372 
373 	mutex_enter(&spa->spa_history_lock);
374 	phys_eof = spa_history_log_to_phys(shpp->sh_eof, shpp);
375 
376 	if (*offp < shpp->sh_pool_create_len) {
377 		/* read in just the zpool create history */
378 		phys_read_off = *offp;
379 		read_len = MIN(*len, shpp->sh_pool_create_len -
380 		    phys_read_off);
381 	} else {
382 		/*
383 		 * Need to reset passed in offset to BOF if the passed in
384 		 * offset has since been overwritten.
385 		 */
386 		*offp = MAX(*offp, shpp->sh_bof);
387 		phys_read_off = spa_history_log_to_phys(*offp, shpp);
388 
389 		/*
390 		 * Read up to the minimum of what the user passed down or
391 		 * the EOF (physical or logical).  If we hit physical EOF,
392 		 * use 'leftover' to read from the physical BOF.
393 		 */
394 		if (phys_read_off <= phys_eof) {
395 			read_len = MIN(*len, phys_eof - phys_read_off);
396 		} else {
397 			read_len = MIN(*len,
398 			    shpp->sh_phys_max_off - phys_read_off);
399 			if (phys_read_off + *len > shpp->sh_phys_max_off) {
400 				leftover = MIN(*len - read_len,
401 				    phys_eof - shpp->sh_pool_create_len);
402 			}
403 		}
404 	}
405 
406 	/* offset for consumer to use next */
407 	*offp += read_len + leftover;
408 
409 	/* tell the consumer how much you actually read */
410 	*len = read_len + leftover;
411 
412 	if (read_len == 0) {
413 		mutex_exit(&spa->spa_history_lock);
414 		dmu_buf_rele(dbp, FTAG);
415 		return (0);
416 	}
417 
418 	err = dmu_read(mos, spa->spa_history, phys_read_off, read_len, buf,
419 	    DMU_READ_PREFETCH);
420 	if (leftover && err == 0) {
421 		err = dmu_read(mos, spa->spa_history, shpp->sh_pool_create_len,
422 		    leftover, buf + read_len, DMU_READ_PREFETCH);
423 	}
424 	mutex_exit(&spa->spa_history_lock);
425 
426 	dmu_buf_rele(dbp, FTAG);
427 	return (err);
428 }
429 
430 /*
431  * The nvlist will be consumed by this call.
432  */
433 static void
434 log_internal(nvlist_t *nvl, const char *operation, spa_t *spa,
435     dmu_tx_t *tx, const char *fmt, va_list adx)
436 {
437 	char *msg;
438 
439 	/*
440 	 * If this is part of creating a pool, not everything is
441 	 * initialized yet, so don't bother logging the internal events.
442 	 * Likewise if the pool is not writeable.
443 	 */
444 	if (tx->tx_txg == TXG_INITIAL || !spa_writeable(spa)) {
445 		fnvlist_free(nvl);
446 		return;
447 	}
448 
449 	msg = kmem_alloc(vsnprintf(NULL, 0, fmt, adx) + 1, KM_SLEEP);
450 	(void) vsprintf(msg, fmt, adx);
451 	fnvlist_add_string(nvl, ZPOOL_HIST_INT_STR, msg);
452 	strfree(msg);
453 
454 	fnvlist_add_string(nvl, ZPOOL_HIST_INT_NAME, operation);
455 	fnvlist_add_uint64(nvl, ZPOOL_HIST_TXG, tx->tx_txg);
456 
457 	if (dmu_tx_is_syncing(tx)) {
458 		spa_history_log_sync(spa, nvl, tx);
459 	} else {
460 		dsl_sync_task_do_nowait(spa_get_dsl(spa), NULL,
461 		    spa_history_log_sync, spa, nvl, 0, tx);
462 	}
463 	/* spa_history_log_sync() will free nvl */
464 }
465 
466 void
467 spa_history_log_internal(spa_t *spa, const char *operation,
468     dmu_tx_t *tx, const char *fmt, ...)
469 {
470 	dmu_tx_t *htx = tx;
471 	va_list adx;
472 
473 	/* create a tx if we didn't get one */
474 	if (tx == NULL) {
475 		htx = dmu_tx_create_dd(spa_get_dsl(spa)->dp_mos_dir);
476 		if (dmu_tx_assign(htx, TXG_WAIT) != 0) {
477 			dmu_tx_abort(htx);
478 			return;
479 		}
480 	}
481 
482 	va_start(adx, fmt);
483 	log_internal(fnvlist_alloc(), operation, spa, htx, fmt, adx);
484 	va_end(adx);
485 
486 	/* if we didn't get a tx from the caller, commit the one we made */
487 	if (tx == NULL)
488 		dmu_tx_commit(htx);
489 }
490 
491 void
492 spa_history_log_internal_ds(dsl_dataset_t *ds, const char *operation,
493     dmu_tx_t *tx, const char *fmt, ...)
494 {
495 	va_list adx;
496 	char namebuf[MAXNAMELEN];
497 	nvlist_t *nvl = fnvlist_alloc();
498 
499 	ASSERT(tx != NULL);
500 
501 	dsl_dataset_name(ds, namebuf);
502 	fnvlist_add_string(nvl, ZPOOL_HIST_DSNAME, namebuf);
503 	fnvlist_add_uint64(nvl, ZPOOL_HIST_DSID, ds->ds_object);
504 
505 	va_start(adx, fmt);
506 	log_internal(nvl, operation, dsl_dataset_get_spa(ds), tx, fmt, adx);
507 	va_end(adx);
508 }
509 
510 void
511 spa_history_log_internal_dd(dsl_dir_t *dd, const char *operation,
512     dmu_tx_t *tx, const char *fmt, ...)
513 {
514 	va_list adx;
515 	char namebuf[MAXNAMELEN];
516 	nvlist_t *nvl = fnvlist_alloc();
517 
518 	ASSERT(tx != NULL);
519 
520 	dsl_dir_name(dd, namebuf);
521 	fnvlist_add_string(nvl, ZPOOL_HIST_DSNAME, namebuf);
522 	fnvlist_add_uint64(nvl, ZPOOL_HIST_DSID,
523 	    dd->dd_phys->dd_head_dataset_obj);
524 
525 	va_start(adx, fmt);
526 	log_internal(nvl, operation, dd->dd_pool->dp_spa, tx, fmt, adx);
527 	va_end(adx);
528 }
529 
530 void
531 spa_history_log_version(spa_t *spa, const char *operation)
532 {
533 #ifdef _KERNEL
534 	uint64_t current_vers = spa_version(spa);
535 
536 	spa_history_log_internal(spa, operation, NULL,
537 	    "pool version %llu; software version %llu/%d; uts %s %s %s %s",
538 	    (u_longlong_t)current_vers, SPA_VERSION, ZPL_VERSION,
539 	    utsname.nodename, utsname.release, utsname.version,
540 	    utsname.machine);
541 	cmn_err(CE_CONT, "!%s version %llu pool %s using %llu", operation,
542 	    (u_longlong_t)current_vers, spa_name(spa), SPA_VERSION);
543 #endif
544 }
545