Skip to content

Commit

Permalink
chore(log): adding higher latency log per IO (mayadata-io#184)
Browse files Browse the repository at this point in the history
When replica gets disconnected with target due to timeout, there might be some IOs that are not responded for long time. There are ZIO delay logs that helps in debugging this issue.
This PR is to logs at uZFS layer regarding high latent IOs.

Signed-off-by: Vishnu Itta <vitta@mayadata.io>
  • Loading branch information
vishnuitta committed Jan 30, 2019
1 parent 81e5e95 commit 3a63e65
Showing 1 changed file with 8 additions and 2 deletions.
10 changes: 8 additions & 2 deletions lib/libzrepl/data_conn.c
Expand Up @@ -41,6 +41,7 @@

#define MAXEVENTS 64

#define IO_THRESHOLD_TIME 30
#define ZVOL_REBUILD_STEP_SIZE (10 * 1024ULL * 1024ULL * 1024ULL) // 10GB
uint64_t zvol_rebuild_step_size = ZVOL_REBUILD_STEP_SIZE;

Expand Down Expand Up @@ -1787,6 +1788,7 @@ uzfs_zvol_io_ack_sender(void *arg)
}
}

latency = 0;
if (zio_cmd->hdr.opcode == ZVOL_OPCODE_READ) {
if (zio_cmd->hdr.status == ZVOL_OP_STATUS_OK) {
/* Send data read from disk */
Expand Down Expand Up @@ -1834,10 +1836,14 @@ uzfs_zvol_io_ack_sender(void *arg)
}
} else if (zio_cmd->hdr.opcode == ZVOL_OPCODE_SYNC) {
atomic_inc_64(&zinfo->sync_req_ack_cnt);
atomic_add_64(&zinfo->sync_latency,
gethrtime() - zio_cmd->io_start_time);
latency = (gethrtime() -
zio_cmd->io_start_time);
atomic_add_64(&zinfo->sync_latency, latency);
}
}
if ((latency >> 30) > IO_THRESHOLD_TIME)
LOG_INFO("IO %d with seq: %lu took %luns",
zio_cmd->hdr.opcode, zio_cmd->hdr.io_seq, latency);
zinfo->zio_cmd_in_ack = NULL;
zio_cmd_free(&zio_cmd);
}
Expand Down

0 comments on commit 3a63e65

Please sign in to comment.