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