Archive-Team
/
zfs
2
0
Fork 0
Code Issues Pull Requests Packages Projects Releases 103 Wiki Activity

Illumos #3618 ::zio dcmd does not show timestamp data 

3618 ::zio dcmd does not show timestamp data
Reviewed by: Adam Leventhal <ahl@delphix.com>
Reviewed by: George Wilson <gwilson@zfsmail.com>
Reviewed by: Christopher Siden <christopher.siden@delphix.com>
Reviewed by: Garrett D'Amore <garrett@damore.org>
Approved by: Dan McDonald <danmcd@nexenta.com>

References:
  http://www.illumos.org/issues/3618
  illumos/illumos-gate@c55e05cb35

Notes on porting to ZFS on Linux:

The original changeset mostly deals with mdb ::zio dcmd.
However, in order to provide the requested functionality
it modifies vdev and zio structures to keep the timing data
in nanoseconds instead of ticks. It is these changes that
are ported over in the commit in hand.

One visible change of this commit is that the default value
of 'zfs_vdev_time_shift' tunable is changed:

    zfs_vdev_time_shift = 6
        to
    zfs_vdev_time_shift = 29

The original value of 6 was inherited from OpenSolaris and
was subotimal - since it shifted the raw tick value - it
didn't compensate for different tick frequencies on Linux and
OpenSolaris. The former has HZ=1000, while the latter HZ=100.

(Which itself led to other interesting performance anomalies
under non-trivial load. The deadline scheduler delays the IO
according to its priority - the lower priority the further
the deadline is set. The delay is measured in units of
"shifted ticks". Since the HZ value was 10 times higher,
the delay units were 10 times shorter. Thus really low
priority IO like resilver (delay is 10 units) and scrub
(delay is 20 units) were scheduled much sooner than intended.
The overall effect is that resilver and scrub IO consumed
more bandwidth at the expense of the other IO.)

Now that the bookkeeping is done is nanoseconds the shift
behaves correctly for any tick frequency (HZ).

Ported-by: Cyril Plisko <cyril.plisko@mountall.com>
Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Closes #1643
This commit is contained in:
Matthew Ahrens 2013-03-21 14:47:36 -08:00 committed by Brian Behlendorf
parent 570d6edf1d
commit cb682a173a
4 changed files with 16 additions and 13 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
include/sys/vdev_impl.h
View File

@ -105,8 +105,8 @@ struct vdev_queue {
avl_tree_t vq_read_tree; avl_tree_t vq_read_tree;
avl_tree_t vq_write_tree; avl_tree_t vq_write_tree;
avl_tree_t vq_pending_tree; avl_tree_t vq_pending_tree;
uint64_t vq_io_complete_ts; hrtime_t vq_io_complete_ts;
uint64_t vq_io_delta_ts; hrtime_t vq_io_delta_ts;
list_t vq_io_list; list_t vq_io_list;
kmutex_t vq_lock; kmutex_t vq_lock;
}; };

4
include/sys/zio.h
View File

@ -410,8 +410,8 @@ struct zio {
uint64_t io_offset; uint64_t io_offset;
uint64_t io_deadline; /* expires at timestamp + deadline */ uint64_t io_deadline; /* expires at timestamp + deadline */
uint64_t io_timestamp; /* submitted at (ticks) */ hrtime_t io_timestamp; /* submitted at */
uint64_t io_delta; /* vdev queue service delta (ticks) */ hrtime_t io_delta; /* vdev queue service delta */
uint64_t io_delay; /* vdev disk service delta (ticks) */ uint64_t io_delay; /* vdev disk service delta (ticks) */
avl_node_t io_offset_node; avl_node_t io_offset_node;
avl_node_t io_deadline_node; avl_node_t io_deadline_node;

8
module/zfs/vdev.c
View File

@ -3219,10 +3219,10 @@ vdev_deadman(vdev_t *vd)
* the spa_deadman_synctime we log a zevent. * the spa_deadman_synctime we log a zevent.
*/ */
fio = avl_first(&vq->vq_pending_tree); fio = avl_first(&vq->vq_pending_tree);
delta = ddi_get_lbolt64() - fio->io_timestamp; delta = gethrtime() - fio->io_timestamp;
if (delta > NSEC_TO_TICK(spa_deadman_synctime(spa))) { if (delta > spa_deadman_synctime(spa)) {
zfs_dbgmsg("SLOW IO: zio timestamp %llu, " zfs_dbgmsg("SLOW IO: zio timestamp %lluns, "
"delta %llu, last io %llu", "delta %lluns, last io %lluns",
fio->io_timestamp, delta, fio->io_timestamp, delta,
vq->vq_io_complete_ts); vq->vq_io_complete_ts);
zfs_ereport_post(FM_EREPORT_ZFS_DELAY, zfs_ereport_post(FM_EREPORT_ZFS_DELAY,

13
module/zfs/vdev_queue.c
View File

@ -44,8 +44,11 @@
int zfs_vdev_max_pending = 10; int zfs_vdev_max_pending = 10;
int zfs_vdev_min_pending = 4; int zfs_vdev_min_pending = 4;
/* deadline = pri + ddi_get_lbolt64() >> time_shift) */ /*
int zfs_vdev_time_shift = 6; * The deadlines are grouped into buckets based on zfs_vdev_time_shift:
* deadline = pri + gethrtime() >> time_shift)
*/
int zfs_vdev_time_shift = 29; /* each bucket is 0.537 seconds */
/* exponential I/O issue ramp-up rate */ /* exponential I/O issue ramp-up rate */
int zfs_vdev_ramp_rate = 2; int zfs_vdev_ramp_rate = 2;
@ -396,7 +399,7 @@ vdev_queue_io(zio_t *zio)
mutex_enter(&vq->vq_lock); mutex_enter(&vq->vq_lock);
zio->io_timestamp = ddi_get_lbolt64(); zio->io_timestamp = gethrtime();
zio->io_deadline = (zio->io_timestamp >> zfs_vdev_time_shift) + zio->io_deadline = (zio->io_timestamp >> zfs_vdev_time_shift) +
zio->io_priority; zio->io_priority;
@ -430,8 +433,8 @@ vdev_queue_io_done(zio_t *zio)
avl_remove(&vq->vq_pending_tree, zio); avl_remove(&vq->vq_pending_tree, zio);
zio->io_delta = ddi_get_lbolt64() - zio->io_timestamp; zio->io_delta = gethrtime() - zio->io_timestamp;
vq->vq_io_complete_ts = ddi_get_lbolt64(); vq->vq_io_complete_ts = gethrtime();
vq->vq_io_delta_ts = vq->vq_io_complete_ts - zio->io_timestamp; vq->vq_io_delta_ts = vq->vq_io_complete_ts - zio->io_timestamp;
for (i = 0; i < zfs_vdev_ramp_rate; i++) { for (i = 0; i < zfs_vdev_ramp_rate; i++) {