Index: sbin/hastd/hastd.h =================================================================== --- sbin/hastd/hastd.h (revision 223717) +++ sbin/hastd/hastd.h (working copy) @@ -51,4 +51,7 @@ void hastd_secondary(struct hast_resource *res, st void primary_config_reload(struct hast_resource *res, struct nv *nv); +int primary_queue_stat(struct hast_queue_stat** statp, int* sizep); +int secondary_queue_stat(struct hast_queue_stat** statp, int* sizep); + #endif /* !_HASTD_H_ */ Index: sbin/hastd/control.c =================================================================== --- sbin/hastd/control.c (revision 223717) +++ sbin/hastd/control.c (working copy) @@ -285,6 +285,116 @@ control_status(struct hastd_config *cfg, struct nv control_status_worker(res, nvout, no); } +static void +control_stat_worker(struct hast_resource *res, struct nv *nvout, + unsigned int no) +{ + struct nv *cnvin, *cnvout; + const char *str; + int error, ii; + + cnvin = cnvout = NULL; + error = 0; + + /* + * Prepare and send command to worker process. + */ + cnvout = nv_alloc(); + nv_add_uint8(cnvout, CONTROL_STAT, "cmd"); + error = nv_error(cnvout); + if (error != 0) { + pjdlog_common(LOG_ERR, 0, error, + "Unable to prepare control header"); + goto end; + } + if (hast_proto_send(res, res->hr_ctrl, cnvout, NULL, 0) < 0) { + error = errno; + pjdlog_errno(LOG_ERR, "Unable to send control header"); + goto end; + } + + /* + * Receive response. + */ + if (hast_proto_recv_hdr(res->hr_ctrl, &cnvin) < 0) { + error = errno; + pjdlog_errno(LOG_ERR, "Unable to receive control header"); + goto end; + } + + error = nv_get_int16(cnvin, "error"); + if (error != 0) + goto end; + + nv_add_uint64(nvout, nv_get_uint64(cnvin, "uptime"), "uptime%u", no); + + for (ii = 0; ; ii++) { + str = nv_get_string(cnvin, "qstat_name%u", ii); + if (str == NULL) + break; + nv_add_string(nvout, str, "queue%u.%u", no, ii); + nv_add_uint64(nvout, nv_get_uint64(cnvin, "qstat_count%u", ii), + "count%u.%u", no, ii); + nv_add_uint64(nvout, nv_get_uint64(cnvin, "qstat_len%u", ii), + "len%u.%u", no, ii); + nv_add_uint64(nvout, nv_get_uint64(cnvin, "qstat_alen%u", ii), + "alen%u.%u", no, ii); + nv_add_uint64(nvout, nv_get_uint64(cnvin, "qstat_await%u", ii), + "await%u.%u", no, ii); + + } +end: + if (cnvin != NULL) + nv_free(cnvin); + if (cnvout != NULL) + nv_free(cnvout); + if (error != 0) + nv_add_int16(nvout, error, "error"); +} + +static void +control_stat(struct hastd_config *cfg, struct nv *nvout, + struct hast_resource *res, const char *name, unsigned int no) +{ + + assert(cfg != NULL); + assert(nvout != NULL); + assert(name != NULL); + + /* Name is always needed. */ + nv_add_string(nvout, name, "resource%u", no); + + if (res == NULL) { + TAILQ_FOREACH(res, &cfg->hc_resources, hr_next) { + if (strcmp(res->hr_name, name) == 0) + break; + } + if (res == NULL) { + nv_add_int16(nvout, EHAST_NOENTRY, "error%u", no); + return; + } + } + assert(res != NULL); + + switch (res->hr_role) { + case HAST_ROLE_PRIMARY: + assert(res->hr_workerpid != 0); + /* FALLTHROUGH */ + case HAST_ROLE_SECONDARY: + if (res->hr_workerpid != 0) + break; + /* FALLTHROUGH */ + default: + return; + } + + /* + * If we are here, it means that we have a worker process, which we + * want to ask some questions. + */ + control_stat_worker(res, nvout, no); +} + void control_handle(struct hastd_config *cfg) { @@ -363,6 +473,10 @@ control_handle(struct hastd_config *cfg) control_status(cfg, nvout, res, res->hr_name, ii++); break; + case HASTCTL_CMD_STAT: + control_stat(cfg, nvout, res, res->hr_name, + ii++); + break; default: pjdlog_error("Invalid command received (%hhu).", cmd); @@ -385,6 +499,9 @@ control_handle(struct hastd_config *cfg) case HASTCTL_CMD_STATUS: control_status(cfg, nvout, NULL, str, ii); break; + case HASTCTL_CMD_STAT: + control_stat(cfg, nvout, NULL, str, ii); + break; default: pjdlog_error("Invalid command received (%hhu).", cmd); @@ -418,8 +535,13 @@ ctrl_thread(void *arg) { struct hast_resource *res = arg; struct nv *nvin, *nvout; + struct hast_queue_stat* qstat; + struct timeval start, now, uptime; + int size, error, ii; uint8_t cmd; + gettimeofday(&start, NULL); + for (;;) { if (hast_proto_recv_hdr(res->hr_ctrl, &nvin) < 0) { if (sigexit_received) @@ -475,6 +597,42 @@ ctrl_thread(void *arg) primary_config_reload(res, nvin); nv_add_int16(nvout, 0, "error"); break; + case CONTROL_STAT: + assert(res->hr_role == HAST_ROLE_PRIMARY || + res->hr_role == HAST_ROLE_SECONDARY); + qstat = NULL; + size = 0; + if (res->hr_role == HAST_ROLE_PRIMARY) + error = primary_queue_stat(&qstat, &size); + else /* res->hr_role == HAST_ROLE_SECONDARY */ + error = secondary_queue_stat(&qstat, &size); + if (error != 0) { + nv_add_int16(nvout, error, "error"); + if (qstat != NULL) + free(qstat); + break; + } + gettimeofday(&now, NULL); + timersub(&now, &start, &uptime); + nv_add_uint64(nvout, (uint64_t)uptime.tv_sec * 1000000 + + uptime.tv_usec, "uptime"); + for (ii = 0; ii < size; ii++) { + nv_add_string(nvout, qstat[ii].qs_name, + "qstat_name%u", ii); + nv_add_uint64(nvout, qstat[ii].qs_count, + "qstat_count%u", ii); + nv_add_uint64(nvout, qstat[ii].qs_len, + "qstat_len%u", ii); + nv_add_uint64(nvout, qstat[ii].qs_alen, + "qstat_alen%u", ii); + nv_add_uint64(nvout, + (uint64_t)qstat[ii].qs_await.tv_sec * + 1000000 + qstat[ii].qs_await.tv_usec, + "qstat_await%u", ii); + } + nv_add_int16(nvout, 0, "error"); + free(qstat); + break; default: nv_add_int16(nvout, EINVAL, "error"); break; Index: sbin/hastd/control.h =================================================================== --- sbin/hastd/control.h (revision 223717) +++ sbin/hastd/control.h (working copy) @@ -34,6 +34,7 @@ #define CONTROL_STATUS 10 #define CONTROL_RELOAD 11 +#define CONTROL_STAT 12 struct hastd_config; struct hast_resource; Index: sbin/hastd/secondary.c =================================================================== --- sbin/hastd/secondary.c (revision 223717) +++ sbin/hastd/secondary.c (working copy) @@ -72,9 +72,15 @@ struct hio { uint8_t hio_cmd; uint64_t hio_offset; uint64_t hio_length; + struct timeval hio_tstart; + uint64_t hio_qlen; TAILQ_ENTRY(hio) hio_next; }; +#define QUEUE_NAME_FREE "free" +#define QUEUE_NAME_DISK "disk" +#define QUEUE_NAME_SEND "send" + static struct hast_resource *gres; /* @@ -84,12 +90,14 @@ static struct hast_resource *gres; static TAILQ_HEAD(, hio) hio_free_list; static pthread_mutex_t hio_free_list_lock; static pthread_cond_t hio_free_list_cond; +static struct hast_queue_stat hio_free_list_stat; /* * Disk thread (the one that do I/O requests) takes requests from this list. */ static TAILQ_HEAD(, hio) hio_disk_list; static pthread_mutex_t hio_disk_list_lock; static pthread_cond_t hio_disk_list_cond; +static struct hast_queue_stat hio_disk_list_stat; /* * There is one recv list for every component, although local components don't * use recv lists as local requests are done synchronously. @@ -97,6 +105,7 @@ static pthread_cond_t hio_disk_list_cond; static TAILQ_HEAD(, hio) hio_send_list; static pthread_mutex_t hio_send_list_lock; static pthread_cond_t hio_send_list_cond; +static struct hast_queue_stat hio_send_list_stat; /* * Maximum number of outstanding I/O requests. @@ -111,6 +120,9 @@ static void *send_thread(void *arg); bool _wakeup; \ \ mtx_lock(&hio_##name##_list_lock); \ + gettimeofday((&(hio)->hio_tstart), NULL); \ + hio_##name##_list_stat.qs_len++; \ + hio->hio_qlen = hio_##name##_list_stat.qs_len; \ _wakeup = TAILQ_EMPTY(&hio_##name##_list); \ TAILQ_INSERT_TAIL(&hio_##name##_list, (hio), hio_next); \ mtx_unlock(&hio_##name##_list_lock); \ @@ -118,14 +130,30 @@ static void *send_thread(void *arg); cv_signal(&hio_##name##_list_cond); \ } while (0) #define QUEUE_TAKE(name, hio) do { \ + struct timeval _tend, _tdiff; \ + \ mtx_lock(&hio_##name##_list_lock); \ while (((hio) = TAILQ_FIRST(&hio_##name##_list)) == NULL) { \ cv_wait(&hio_##name##_list_cond, \ &hio_##name##_list_lock); \ } \ TAILQ_REMOVE(&hio_##name##_list, (hio), hio_next); \ + hio_##name##_list_stat.qs_count++; \ + assert(hio_##name##_list_stat.qs_len > 0); \ + hio_##name##_list_stat.qs_len--; \ + hio_##name##_list_stat.qs_alen += \ + (hio)->hio_qlen; \ + gettimeofday(&_tend, NULL); \ + timersub(&_tend, &(hio)->hio_tstart, &_tdiff); \ + timeradd(&hio_##name##_list_stat.qs_await, \ + &_tdiff, &hio_##name##_list_stat.qs_await); \ mtx_unlock(&hio_##name##_list_lock); \ } while (0) +#define QUEUE_STAT(name, stat) do { \ + mtx_lock(&hio_##name##_list_lock); \ + *(stat) = hio_##name##_list_stat; \ + mtx_unlock(&hio_##name##_list_lock); \ +} while (0) static void init_environment(void) @@ -139,12 +167,18 @@ init_environment(void) TAILQ_INIT(&hio_free_list); mtx_init(&hio_free_list_lock); cv_init(&hio_free_list_cond); + bzero(&hio_free_list_stat, sizeof(hio_free_list_stat)); + hio_free_list_stat.qs_name = QUEUE_NAME_FREE; TAILQ_INIT(&hio_disk_list); mtx_init(&hio_disk_list_lock); cv_init(&hio_disk_list_cond); + bzero(&hio_disk_list_stat, sizeof(hio_disk_list_stat)); + hio_disk_list_stat.qs_name = QUEUE_NAME_DISK; TAILQ_INIT(&hio_send_list); mtx_init(&hio_send_list_lock); cv_init(&hio_send_list_cond); + bzero(&hio_send_list_stat, sizeof(hio_send_list_stat)); + hio_send_list_stat.qs_name = QUEUE_NAME_SEND; /* * Allocate requests pool and initialize requests. @@ -164,6 +198,9 @@ init_environment(void) (size_t)MAXPHYS); } TAILQ_INSERT_HEAD(&hio_free_list, hio, hio_next); + gettimeofday((&hio->hio_tstart), NULL); + hio_free_list_stat.qs_len++; + hio->hio_qlen = hio_free_list_stat.qs_len; } } @@ -366,6 +403,31 @@ init_remote(struct hast_resource *res, struct nv * } } +int +secondary_queue_stat(struct hast_queue_stat** qstatp, int* sizep) +{ + struct hast_queue_stat* qstat; + int size; + + size = 3; + qstat = malloc(sizeof(qstat[0]) * size); + if (qstat == NULL) { + pjdlog_error("Unable to allocate memory for statistics (size=%zu).", + sizeof(qstat[0]) * size); + *qstatp = NULL; + *sizep = 0; + return (ENOMEM); + } + + QUEUE_STAT(free, &qstat[0]); + QUEUE_STAT(disk, &qstat[1]); + QUEUE_STAT(send, &qstat[2]); + + *qstatp = qstat; + *sizep = size; + return (0); +} + void hastd_secondary(struct hast_resource *res, struct nv *nvin) { Index: sbin/hastd/hast.h =================================================================== --- sbin/hastd/hast.h (revision 223717) +++ sbin/hastd/hast.h (working copy) @@ -35,6 +35,7 @@ #include #include +#include #include @@ -65,6 +66,7 @@ #define HASTCTL_CMD_UNKNOWN 0 #define HASTCTL_CMD_SETROLE 1 #define HASTCTL_CMD_STATUS 2 +#define HASTCTL_CMD_STAT 3 #define HAST_ROLE_UNDEF 0 #define HAST_ROLE_INIT 1 @@ -233,6 +235,21 @@ struct hast_resource { TAILQ_ENTRY(hast_resource) hr_next; }; +struct hast_queue_stat { + /* Queue name. */ + const char* qs_name; + /* Number of requests visited the queue. */ + uint64_t qs_count; + /* Current queue length. */ + uint64_t qs_len; + /* Accumulated queue length. */ + uint64_t qs_alen; + /* Accumulated wait time. */ + struct timeval qs_await; +}; + +#define HAST_MAX_QUEUES 5 + struct hastd_config *yy_config_parse(const char *config, bool exitonerror); void yy_config_free(struct hastd_config *config); Index: sbin/hastd/primary.c =================================================================== --- sbin/hastd/primary.c (revision 223717) +++ sbin/hastd/primary.c (working copy) @@ -89,11 +89,29 @@ struct hio { * Structure used to communicate with GEOM Gate class. */ struct g_gate_ctl_io hio_ggio; + /* + * Time when the request was inserted in a queue. + */ + struct timeval *hio_tstart; + /* + * Queue length when the request entered it. + */ + uint64_t *hio_qlen; TAILQ_ENTRY(hio) *hio_next; }; +#define hio_free_tstart hio_tstart[0] +#define hio_done_tstart hio_tstart[0] +#define hio_free_qlen hio_qlen[0] +#define hio_done_qlen hio_qlen[0] #define hio_free_next hio_next[0] #define hio_done_next hio_next[0] +#define QUEUE_NAME_FREE "free" +#define QUEUE_NAME_LOCAL_SEND "local_send" +#define QUEUE_NAME_REMOTE_SEND "remote_send" +#define QUEUE_NAME_REMOTE_RECV "remote_recv" +#define QUEUE_NAME_DONE "done" + /* * Free list holds unused structures. When free list is empty, we have to wait * until some in-progress requests are freed. @@ -101,6 +119,7 @@ struct hio { static TAILQ_HEAD(, hio) hio_free_list; static pthread_mutex_t hio_free_list_lock; static pthread_cond_t hio_free_list_cond; +static struct hast_queue_stat hio_free_list_stat; /* * There is one send list for every component. One requests is placed on all * send lists - each component gets the same request, but each component is @@ -109,6 +128,7 @@ static pthread_cond_t hio_free_list_cond; static TAILQ_HEAD(, hio) *hio_send_list; static pthread_mutex_t *hio_send_list_lock; static pthread_cond_t *hio_send_list_cond; +static struct hast_queue_stat *hio_send_list_stat; /* * There is one recv list for every component, although local components don't * use recv lists as local requests are done synchronously. @@ -116,6 +136,7 @@ static pthread_cond_t *hio_send_list_cond; static TAILQ_HEAD(, hio) *hio_recv_list; static pthread_mutex_t *hio_recv_list_lock; static pthread_cond_t *hio_recv_list_cond; +static struct hast_queue_stat *hio_recv_list_stat; /* * Request is placed on done list by the slowest component (the one that * decreased hio_countdown from 1 to 0). @@ -123,6 +144,7 @@ static pthread_cond_t *hio_recv_list_cond; static TAILQ_HEAD(, hio) hio_done_list; static pthread_mutex_t hio_done_list_lock; static pthread_cond_t hio_done_list_cond; +static struct hast_queue_stat hio_done_list_stat; /* * Structure below are for interaction with sync thread. */ @@ -154,11 +176,55 @@ static pthread_mutex_t metadata_lock; #define ISCONNECTED(res, no) \ ((res)->hr_remotein != NULL && (res)->hr_remoteout != NULL) +#define QUEUE_INSERT_STAT1(hio, name, ncomp) do { \ + gettimeofday((&(hio)->hio_tstart[(ncomp)]), NULL); \ + hio_##name##_list_stat[(ncomp)].qs_len++; \ + (hio)->hio_qlen[(ncomp)] = \ + hio_##name##_list_stat[(ncomp)].qs_len; \ +} while (0) +#define QUEUE_INSERT_STAT2(hio, name) do { \ + hio_##name##_list_stat.qs_len++; \ + (hio)->hio_##name##_qlen = hio_##name##_list_stat.qs_len; \ +} while (0) +#define QUEUE_TAKE_STAT1(hio, name, ncomp) do { \ + struct timeval _tend, _tdiff; \ + hio_##name##_list_stat[(ncomp)].qs_count++; \ + assert(hio_##name##_list_stat[(ncomp)].qs_len > 0); \ + hio_##name##_list_stat[(ncomp)].qs_len--; \ + hio_##name##_list_stat[(ncomp)].qs_alen += \ + (hio)->hio_qlen[(ncomp)]; \ + gettimeofday(&_tend, NULL); \ + timersub(&_tend, &(hio)->hio_tstart[(ncomp)], &_tdiff); \ + timeradd(&hio_##name##_list_stat[(ncomp)].qs_await, \ + &_tdiff, &hio_##name##_list_stat[(ncomp)].qs_await); \ +} while (0) +#define QUEUE_TAKE_STAT2(hio, name) do { \ + hio_##name##_list_stat.qs_count++; \ + assert(hio_##name##_list_stat.qs_len > 0); \ + hio_##name##_list_stat.qs_len--; \ + hio_##name##_list_stat.qs_alen += (hio)->hio_##name##_qlen; \ + gettimeofday(&_tend, NULL); \ + timersub(&_tend, &(hio)->hio_##name##_tstart, &_tdiff); \ + timeradd(&hio_##name##_list_stat.qs_await, \ + &_tdiff, &hio_##name##_list_stat.qs_await); \ +} while (0) +#define QUEUE_STAT1(name, stat, ncomp) do { \ + mtx_lock(&hio_##name##_list_lock[(ncomp)]); \ + *(stat) = hio_##name##_list_stat[(ncomp)]; \ + mtx_unlock(&hio_##name##_list_lock[(ncomp)]); \ +} while (0) +#define QUEUE_STAT2(name, stat) do { \ + mtx_lock(&hio_##name##_list_lock); \ + *(stat) = hio_##name##_list_stat; \ + mtx_unlock(&hio_##name##_list_lock); \ +} while (0) + #define QUEUE_INSERT1(hio, name, ncomp) do { \ bool _wakeup; \ \ mtx_lock(&hio_##name##_list_lock[(ncomp)]); \ _wakeup = TAILQ_EMPTY(&hio_##name##_list[(ncomp)]); \ + QUEUE_INSERT_STAT1((hio), name, (ncomp)); \ TAILQ_INSERT_TAIL(&hio_##name##_list[(ncomp)], (hio), \ hio_next[(ncomp)]); \ mtx_unlock(&hio_##name##_list_lock[ncomp]); \ @@ -169,7 +235,9 @@ static pthread_mutex_t metadata_lock; bool _wakeup; \ \ mtx_lock(&hio_##name##_list_lock); \ + gettimeofday((&(hio)->hio_##name##_tstart), NULL); \ _wakeup = TAILQ_EMPTY(&hio_##name##_list); \ + QUEUE_INSERT_STAT2((hio), name); \ TAILQ_INSERT_TAIL(&hio_##name##_list, (hio), hio_##name##_next);\ mtx_unlock(&hio_##name##_list_lock); \ if (_wakeup) \ @@ -189,16 +257,20 @@ static pthread_mutex_t metadata_lock; if (hio != NULL) { \ TAILQ_REMOVE(&hio_##name##_list[(ncomp)], (hio), \ hio_next[(ncomp)]); \ + QUEUE_TAKE_STAT1((hio), name, (ncomp)); \ } \ mtx_unlock(&hio_##name##_list_lock[(ncomp)]); \ } while (0) #define QUEUE_TAKE2(hio, name) do { \ + struct timeval _tend, _tdiff; \ + \ mtx_lock(&hio_##name##_list_lock); \ while (((hio) = TAILQ_FIRST(&hio_##name##_list)) == NULL) { \ cv_wait(&hio_##name##_list_cond, \ &hio_##name##_list_lock); \ } \ TAILQ_REMOVE(&hio_##name##_list, (hio), hio_##name##_next); \ + QUEUE_TAKE_STAT2((hio), name); \ mtx_unlock(&hio_##name##_list_lock); \ } while (0) @@ -339,6 +411,12 @@ init_environment(struct hast_resource *res __unuse "Unable to allocate %zu bytes of memory for send list condition variables.", sizeof(hio_send_list_cond[0]) * ncomps); } + hio_send_list_stat = malloc(sizeof(hio_send_list_stat[0]) * ncomps); + if (hio_send_list_stat == NULL) { + primary_exitx(EX_TEMPFAIL, + "Unable to allocate %zu bytes of memory for send list statistics variables.", + sizeof(hio_send_list_stat[0]) * ncomps); + } hio_recv_list = malloc(sizeof(hio_recv_list[0]) * ncomps); if (hio_recv_list == NULL) { primary_exitx(EX_TEMPFAIL, @@ -357,6 +435,12 @@ init_environment(struct hast_resource *res __unuse "Unable to allocate %zu bytes of memory for recv list condition variables.", sizeof(hio_recv_list_cond[0]) * ncomps); } + hio_recv_list_stat = malloc(sizeof(hio_recv_list_stat[0]) * ncomps); + if (hio_recv_list_stat == NULL) { + primary_exitx(EX_TEMPFAIL, + "Unable to allocate %zu bytes of memory for recv list statistics variables.", + sizeof(hio_recv_list_stat[0]) * ncomps); + } hio_remote_lock = malloc(sizeof(hio_remote_lock[0]) * ncomps); if (hio_remote_lock == NULL) { primary_exitx(EX_TEMPFAIL, @@ -370,18 +454,28 @@ init_environment(struct hast_resource *res __unuse TAILQ_INIT(&hio_free_list); mtx_init(&hio_free_list_lock); cv_init(&hio_free_list_cond); + bzero(&hio_free_list_stat, sizeof(hio_free_list_stat)); + hio_free_list_stat.qs_name = QUEUE_NAME_FREE; for (ii = 0; ii < HAST_NCOMPONENTS; ii++) { TAILQ_INIT(&hio_send_list[ii]); mtx_init(&hio_send_list_lock[ii]); cv_init(&hio_send_list_cond[ii]); + bzero(&hio_send_list_stat[ii], sizeof(hio_send_list_stat[ii])); + hio_send_list_stat[ii].qs_name = ISREMOTE(ii) ? + QUEUE_NAME_REMOTE_SEND : QUEUE_NAME_LOCAL_SEND; TAILQ_INIT(&hio_recv_list[ii]); mtx_init(&hio_recv_list_lock[ii]); cv_init(&hio_recv_list_cond[ii]); + bzero(&hio_recv_list_stat[ii], sizeof(hio_recv_list_stat[ii])); + hio_recv_list_stat[ii].qs_name = ISREMOTE(ii) ? + QUEUE_NAME_REMOTE_RECV : ""; rw_init(&hio_remote_lock[ii]); } TAILQ_INIT(&hio_done_list); mtx_init(&hio_done_list_lock); cv_init(&hio_done_list_cond); + bzero(&hio_done_list_stat, sizeof(hio_done_list_stat)); + hio_done_list_stat.qs_name = QUEUE_NAME_DONE; mtx_init(&metadata_lock); /* @@ -401,6 +495,18 @@ init_environment(struct hast_resource *res __unuse "Unable allocate %zu bytes of memory for hio errors.", sizeof(hio->hio_errors[0]) * ncomps); } + hio->hio_qlen = malloc(sizeof(hio->hio_qlen[0]) * ncomps); + if (hio->hio_qlen == NULL) { + primary_exitx(EX_TEMPFAIL, + "Unable to allocate %zu bytes of memory for hio_qlen field.", + sizeof(hio->hio_qlen[0]) * ncomps); + } + hio->hio_tstart = malloc(sizeof(hio->hio_tstart[0]) * ncomps); + if (hio->hio_tstart == NULL) { + primary_exitx(EX_TEMPFAIL, + "Unable to allocate %zu bytes of memory for hio_tstart field.", + sizeof(hio->hio_tstart[0]) * ncomps); + } hio->hio_next = malloc(sizeof(hio->hio_next[0]) * ncomps); if (hio->hio_next == NULL) { primary_exitx(EX_TEMPFAIL, @@ -417,6 +523,9 @@ init_environment(struct hast_resource *res __unuse hio->hio_ggio.gctl_length = MAXPHYS; hio->hio_ggio.gctl_error = 0; TAILQ_INSERT_HEAD(&hio_free_list, hio, hio_free_next); + gettimeofday((&hio->hio_free_tstart), NULL); + hio_free_list_stat.qs_len++; + hio->hio_free_qlen = hio_free_list_stat.qs_len; } } @@ -829,6 +938,33 @@ init_ggate(struct hast_resource *res) res->hr_provname); } +int +primary_queue_stat(struct hast_queue_stat** qstatp, int* sizep) +{ + struct hast_queue_stat* qstat; + int size; + + size = 5; + qstat = malloc(sizeof(qstat[0]) * size); + if (qstat == NULL) { + pjdlog_error("Unable to allocate memory for statistics (size=%zu).", + sizeof(qstat[0]) * size); + *qstatp = NULL; + *sizep = 0; + return (ENOMEM); + } + + QUEUE_STAT2(free, &qstat[0]); + QUEUE_STAT1(send, &qstat[1], 0); + QUEUE_STAT1(send, &qstat[2], 1); + QUEUE_STAT1(recv, &qstat[3], 1); + QUEUE_STAT2(done, &qstat[4]); + + *qstatp = qstat; + *sizep = size; + return (0); +} + void hastd_primary(struct hast_resource *res) { @@ -1459,6 +1595,7 @@ remote_send_thread(void *arg) */ mtx_lock(&hio_recv_list_lock[ncomp]); wakeup = TAILQ_EMPTY(&hio_recv_list[ncomp]); + QUEUE_INSERT_STAT1(hio, recv, ncomp); TAILQ_INSERT_TAIL(&hio_recv_list[ncomp], hio, hio_next[ncomp]); mtx_unlock(&hio_recv_list_lock[ncomp]); if (hast_proto_send(res, res->hr_remoteout, nv, data, @@ -1477,7 +1614,7 @@ remote_send_thread(void *arg) */ mtx_lock(&hio_recv_list_lock[ncomp]); TAILQ_REMOVE(&hio_recv_list[ncomp], hio, hio_next[ncomp]); - mtx_unlock(&hio_recv_list_lock[ncomp]); + QUEUE_TAKE_STAT1(hio, recv, ncomp); goto done_queue; } rw_unlock(&hio_remote_lock[ncomp]); @@ -1554,7 +1691,7 @@ remote_recv_thread(void *arg) PJDLOG_ASSERT(hio != NULL); TAILQ_REMOVE(&hio_recv_list[ncomp], hio, hio_next[ncomp]); - mtx_unlock(&hio_recv_list_lock[ncomp]); + QUEUE_TAKE_STAT1(hio, recv, ncomp); goto done_queue; } if (hast_proto_recv_hdr(res->hr_remotein, &nv) < 0) { @@ -1576,6 +1713,7 @@ remote_recv_thread(void *arg) if (hio->hio_ggio.gctl_seq == seq) { TAILQ_REMOVE(&hio_recv_list[ncomp], hio, hio_next[ncomp]); + QUEUE_TAKE_STAT1(hio, recv, ncomp); break; } } Index: sbin/hastctl/hastctl.c =================================================================== --- sbin/hastctl/hastctl.c (revision 223717) +++ sbin/hastctl/hastctl.c (working copy) @@ -71,7 +71,8 @@ enum { CMD_CREATE, CMD_ROLE, CMD_STATUS, - CMD_DUMP + CMD_DUMP, + CMD_STAT }; static __dead2 void @@ -89,6 +90,9 @@ usage(void) " %s status [-d] [-c config] [all | name ...]\n", getprogname()); fprintf(stderr, + " %s stat [-d] [-c config] [-w wait [-q howmany] [-T u | d | ]] [all | name ...]\n", + getprogname()); + fprintf(stderr, " %s dump [-d] [-c config] [all | name ...]\n", getprogname()); exit(EX_USAGE); @@ -356,16 +360,180 @@ control_status(struct nv *nv) return (ret); } +static int +control_stat(struct nv *nv, bool diff, const char *timefmt) +{ + unsigned int ii, jj, kk; + const char *resource, *queue; + int error, ret, newsize, cres; + uint64_t count, len, alen, await, uptime, nreq; + bool firstrun; + static struct { + char resource[255]; + uint64_t uptime; + struct hast_queue_stat qstat[HAST_MAX_QUEUES]; + } *qstat = NULL; + struct hast_queue_stat *p; + static unsigned int size = 0; + time_t now; + struct tm lt; + char buf[255]; + + ret = 0; + newsize = 0; + + if (!diff) { + /* + * Print raw data. + */ + for (ii = 0; ; ii++) { + resource = nv_get_string(nv, "resource%u", ii); + if (resource == NULL) + break; + error = nv_get_int16(nv, "error%u", ii); + if (error != 0) { + if (ret == 0) + ret = error; + printf("%s.error: %d\n", resource, error); + continue; + } + printf("%s.uptime: %llu\n", resource, + nv_get_uint64(nv, "uptime%u", ii)); + for (jj = 0; ; jj++) { + queue = nv_get_string(nv, "queue%u.%u", ii, jj); + if (queue == NULL) + break; + + printf("%s.%s.count: %llu\n", resource, queue, + nv_get_uint64(nv, "count%u.%u", ii, jj)); + printf("%s.%s.current_lengh: %llu\n", resource, queue, + nv_get_uint64(nv, "len%u.%u", ii, jj)); + printf("%s.%s.accumulated_lengh: %llu\n", resource, queue, + nv_get_uint64(nv, "alen%u.%u", ii, jj)); + printf("%s.%s.accumulated_wait: %llu\n", resource, queue, + nv_get_uint64(nv, "await%u.%u", ii, jj)); + } + } + return (ret); + } + + /* + * Print difference. + */ + firstrun = (qstat == NULL) ? true : false; + + for (ii = 0; ; ii++) { + resource = nv_get_string(nv, "resource%u", ii); + if (resource == NULL) + break; + newsize++; + } + if (newsize == 0) + pjdlog_exit(EX_UNAVAILABLE, "No resources returned."); + if (firstrun) { + size = newsize; + qstat = malloc(sizeof(qstat[0]) * size); + if (qstat == NULL) { + pjdlog_exit(EX_OSERR, + "Unable to allocate memory for statistics (size=%zu)", + sizeof(qstat[0]) * size); + } + bzero(qstat, sizeof(qstat[0]) * size); + } + if (timefmt != NULL) { + now = time(NULL); + lt = *localtime(&now); + strftime(buf, sizeof(buf), timefmt, <); + printf(" %s\n", buf); + } + printf("%15s%15s%15s %s\n", + "req/sec", "length", "wait(usec)", "resource/queue"); + printf("%15s%15s%15s %s\n", + "-------------", "-------------", "-------------", + "--------------------------"); + + for (ii = 0; ; ii++) { + resource = nv_get_string(nv, "resource%u", ii); + if (resource == NULL) + break; + if (firstrun) { + cres = ii; + strncpy(qstat[cres].resource, resource, + sizeof(qstat[cres].resource) - 1); + } else { + cres = -1; + for (kk = 0; kk < size; kk++) { + if (strcmp(resource, qstat[kk].resource) == 0) { + cres = kk; + break; + } + if (cres == -1) { + pjdlog_exit(EX_UNAVAILABLE, + "Configuration changed."); + } + } + } + error = nv_get_int16(nv, "error%u", ii); + if (error != 0) { + if (ret == 0) + ret = error; + printf("%s: error: %d\n", resource, error); + continue; + } + uptime = nv_get_uint64(nv, "uptime%u", ii); + for (jj = 0; jj < HAST_MAX_QUEUES; jj++) { + queue = nv_get_string(nv, "queue%u.%u", ii, jj); + if (queue == NULL) + break; + count = nv_get_uint64(nv, "count%u.%u", ii, jj); + len = nv_get_uint64(nv, "len%u.%u", ii, jj); + alen = nv_get_uint64(nv, "alen%u.%u", ii, jj); + await = nv_get_uint64(nv, "await%u.%u", ii, jj); + + if (uptime > qstat[cres].uptime) { + p = &qstat[cres].qstat[jj]; + nreq = count - p->qs_count; + if (nreq > 0) { + printf("%15.2f%15.2f%15.2f %s/%s\n", + 1.0 * nreq * 1000000 / + (uptime - qstat[cres].uptime), + 1.0 * (alen - p->qs_alen) / nreq, + 1.0 * (await - p->qs_await.tv_sec * + 1000000 - p->qs_await.tv_usec) / nreq, + resource, queue); + } else { + printf("%15d%15s%15s %s/%s\n", + 0, "-", "-", resource, queue); + } + } + qstat[cres].qstat[jj].qs_count = count; + qstat[cres].qstat[jj].qs_len = len; + qstat[cres].qstat[jj].qs_alen = alen; + qstat[cres].qstat[jj].qs_await.tv_sec = await / 1000000; + qstat[cres].qstat[jj].qs_await.tv_usec = await % 1000000; + } + qstat[cres].uptime = uptime; + printf("%15s%15s%15s %s\n", + "-------------", "-------------", "-------------", + "--------------------------"); + } + + return (ret); +} + int main(int argc, char *argv[]) { struct nv *nv; - int64_t mediasize, extentsize, keepdirty; + int64_t mediasize, extentsize, keepdirty, wait, howmany; int cmd, debug, error, ii; - const char *optstr; + const char *optstr, *timefmt; debug = 0; mediasize = extentsize = keepdirty = 0; + wait = 0; + howmany = -1; + timefmt = NULL; if (argc == 1) usage(); @@ -382,6 +550,9 @@ main(int argc, char *argv[]) } else if (strcmp(argv[1], "dump") == 0) { cmd = CMD_DUMP; optstr = "c:dh"; + } else if (strcmp(argv[1], "stat") == 0) { + cmd = CMD_STAT; + optstr = "c:dhw:q:T:"; } else usage(); @@ -413,6 +584,22 @@ main(int argc, char *argv[]) if (expand_number(optarg, &mediasize) < 0) err(1, "Invalid mediasize"); break; + case 'w': + if (expand_number(optarg, &wait) < 0) + err(1, "Invalid wait"); + break; + case 'q': + if (expand_number(optarg, &howmany) < 0) + err(1, "Invalid howmany"); + break; + case 'T': + if (strcmp(optarg, "u") == 0) + timefmt = "%s"; + else if (strcmp(optarg, "d") == 0) + timefmt = "%+"; + else + timefmt = optarg; + break; case 'h': default: usage(); @@ -435,96 +622,118 @@ main(int argc, char *argv[]) cfg = yy_config_parse(cfgpath, true); assert(cfg != NULL); - switch (cmd) { - case CMD_CREATE: - control_create(argc, argv, mediasize, extentsize, keepdirty); - /* NOTREACHED */ - assert(!"What are we doing here?!"); - break; - case CMD_DUMP: - /* Dump metadata from local component of the given resource. */ - control_dump(argc, argv); - /* NOTREACHED */ - assert(!"What are we doing here?!"); - break; - case CMD_ROLE: - /* Change role for the given resources. */ - if (argc < 2) - usage(); - nv = nv_alloc(); - nv_add_uint8(nv, HASTCTL_CMD_SETROLE, "cmd"); - if (strcmp(argv[0], "init") == 0) - nv_add_uint8(nv, HAST_ROLE_INIT, "role"); - else if (strcmp(argv[0], "primary") == 0) - nv_add_uint8(nv, HAST_ROLE_PRIMARY, "role"); - else if (strcmp(argv[0], "secondary") == 0) - nv_add_uint8(nv, HAST_ROLE_SECONDARY, "role"); - else - usage(); - for (ii = 0; ii < argc - 1; ii++) - nv_add_string(nv, argv[ii + 1], "resource%d", ii); - break; - case CMD_STATUS: - /* Obtain status of the given resources. */ - nv = nv_alloc(); - nv_add_uint8(nv, HASTCTL_CMD_STATUS, "cmd"); - if (argc == 0) - nv_add_string(nv, "all", "resource%d", 0); - else { - for (ii = 0; ii < argc; ii++) - nv_add_string(nv, argv[ii], "resource%d", ii); + do { + switch (cmd) { + case CMD_CREATE: + control_create(argc, argv, mediasize, extentsize, keepdirty); + /* NOTREACHED */ + assert(!"What are we doing here?!"); + break; + case CMD_DUMP: + /* Dump metadata from local component of the given resource. */ + control_dump(argc, argv); + /* NOTREACHED */ + assert(!"What are we doing here?!"); + break; + case CMD_ROLE: + /* Change role for the given resources. */ + if (argc < 2) + usage(); + nv = nv_alloc(); + nv_add_uint8(nv, HASTCTL_CMD_SETROLE, "cmd"); + if (strcmp(argv[0], "init") == 0) + nv_add_uint8(nv, HAST_ROLE_INIT, "role"); + else if (strcmp(argv[0], "primary") == 0) + nv_add_uint8(nv, HAST_ROLE_PRIMARY, "role"); + else if (strcmp(argv[0], "secondary") == 0) + nv_add_uint8(nv, HAST_ROLE_SECONDARY, "role"); + else + usage(); + for (ii = 0; ii < argc - 1; ii++) + nv_add_string(nv, argv[ii + 1], "resource%d", ii); + break; + case CMD_STATUS: + /* Obtain status of the given resources. */ + nv = nv_alloc(); + nv_add_uint8(nv, HASTCTL_CMD_STATUS, "cmd"); + if (argc == 0) + nv_add_string(nv, "all", "resource%d", 0); + else { + for (ii = 0; ii < argc; ii++) + nv_add_string(nv, argv[ii], "resource%d", ii); + } + break; + case CMD_STAT: + /* Obtain statistics for the given resources. */ + nv = nv_alloc(); + nv_add_uint8(nv, HASTCTL_CMD_STAT, "cmd"); + if (argc == 0) + nv_add_string(nv, "all", "resource%d", 0); + else { + for (ii = 0; ii < argc; ii++) + nv_add_string(nv, argv[ii], "resource%d", ii); + } + break; + default: + assert(!"Impossible command!"); } - break; - default: - assert(!"Impossible command!"); - } - /* Setup control connection... */ - if (proto_client(NULL, cfg->hc_controladdr, &controlconn) < 0) { - pjdlog_exit(EX_OSERR, - "Unable to setup control connection to %s", - cfg->hc_controladdr); - } - /* ...and connect to hastd. */ - if (proto_connect(controlconn, HAST_TIMEOUT) < 0) { - pjdlog_exit(EX_OSERR, "Unable to connect to hastd via %s", - cfg->hc_controladdr); - } + /* Setup control connection... */ + if (proto_client(NULL, cfg->hc_controladdr, &controlconn) < 0) { + pjdlog_exit(EX_OSERR, + "Unable to setup control connection to %s", + cfg->hc_controladdr); + } + /* ...and connect to hastd. */ + if (proto_connect(controlconn, HAST_TIMEOUT) < 0) { + pjdlog_exit(EX_OSERR, "Unable to connect to hastd via %s", + cfg->hc_controladdr); + } - if (drop_privs(NULL) != 0) - exit(EX_CONFIG); + if (cmd != CMD_STAT && drop_privs(NULL) != 0) + exit(EX_CONFIG); - /* Send the command to the server... */ - if (hast_proto_send(NULL, controlconn, nv, NULL, 0) < 0) { - pjdlog_exit(EX_UNAVAILABLE, - "Unable to send command to hastd via %s", - cfg->hc_controladdr); - } - nv_free(nv); - /* ...and receive reply. */ - if (hast_proto_recv_hdr(controlconn, &nv) < 0) { - pjdlog_exit(EX_UNAVAILABLE, - "cannot receive reply from hastd via %s", - cfg->hc_controladdr); - } + /* Send the command to the server... */ + if (hast_proto_send(NULL, controlconn, nv, NULL, 0) < 0) { + pjdlog_exit(EX_UNAVAILABLE, + "Unable to send command to hastd via %s", + cfg->hc_controladdr); + } + nv_free(nv); + /* ...and receive reply. */ + if (hast_proto_recv_hdr(controlconn, &nv) < 0) { + pjdlog_exit(EX_UNAVAILABLE, + "cannot receive reply from hastd via %s", + cfg->hc_controladdr); + } - error = nv_get_int16(nv, "error"); - if (error != 0) { - pjdlog_exitx(EX_SOFTWARE, "Error %d received from hastd.", - error); - } - nv_set_error(nv, 0); + error = nv_get_int16(nv, "error"); + if (error != 0) { + pjdlog_exitx(EX_SOFTWARE, "Error %d received from hastd.", + error); + } + nv_set_error(nv, 0); - switch (cmd) { - case CMD_ROLE: - error = control_set_role(nv, argv[0]); - break; - case CMD_STATUS: - error = control_status(nv); - break; - default: - assert(!"Impossible command!"); - } + switch (cmd) { + case CMD_ROLE: + error = control_set_role(nv, argv[0]); + break; + case CMD_STATUS: + error = control_status(nv); + break; + case CMD_STAT: + error = control_stat(nv, wait > 0, timefmt); + break; + default: + assert(!"Impossible command!"); + } + proto_close(controlconn); + controlconn = NULL; + + howmany--; + + } while (cmd == CMD_STAT && wait > 0 && howmany != 0 && sleep(wait) == 0); + exit(error); } Index: sbin/hastctl/hastctl.8 =================================================================== --- sbin/hastctl/hastctl.8 (revision 223717) +++ sbin/hastctl/hastctl.8 (working copy) @@ -54,6 +54,14 @@ .Op Fl c Ar config .Op Ar all | name ... .Nm +.Cm stat +.Op Fl d +.Op Fl c Ar config +.Op Fl w Ar wait +.Op Fl q Ar howmany +.Op Fl T Ar u | Ar d | Ar format +.Op Ar all | name ... +.Nm .Cm dump .Op Fl d .Op Fl c Ar config @@ -141,6 +149,25 @@ will not be created on secondary node. .El .It Cm status Present status of the configured resources. +.It Cm stat +Print queue statistics. +Additional options include: +.Bl -tag -width ".Fl T Ar u | Ar d | Ar format" +.It Fl w Ar wait +Repeatedly display statistics at intervals of +.Ar wait +seconds. +.It Fl q Ar howmany +When repeatedly displaying statistics exit after +.Ar howmany +outputs. +.It Fl T Ar u | Ar d | Ar format +Display also a timestamp. +Specify +.Ar u +for the number of seconds since the Epoch, UTC, specify +.Ar d +for standard date format, or specify a custom format. .It Cm dump Dump metadata stored on local component for the configured resources. .El