diff options
| -rw-r--r-- | server/display-channel.cpp | 6 | ||||
| -rw-r--r-- | server/red-channel-client.cpp | 75 | ||||
| -rw-r--r-- | server/red-channel.h | 6 | ||||
| -rw-r--r-- | server/red-pipe-item.h | 4 |
4 files changed, 89 insertions, 2 deletions
diff --git a/server/display-channel.cpp b/server/display-channel.cpp index 4bd0cf41..5c96be5c 100644 --- a/server/display-channel.cpp +++ b/server/display-channel.cpp @@ -78,11 +78,13 @@ void display_channel_compress_stats_reset(DisplayChannel *display) void display_channel_compress_stats_print(DisplayChannel *display) { + spice_return_if_fail(display); + + queue_print_stats(); + #ifdef COMPRESS_STAT uint32_t id; - spice_return_if_fail(display); - id = display->id(); spice_info("==> Compression stats for display %u", id); diff --git a/server/red-channel-client.cpp b/server/red-channel-client.cpp index b7567ffb..3f8d64d1 100644 --- a/server/red-channel-client.cpp +++ b/server/red-channel-client.cpp @@ -489,8 +489,82 @@ void RedChannelClient::send_empty_msg(RedPipeItem *base) begin_send_message(); } +#ifdef QUEUE_STAT + +static const struct { + const char desc[8]; + int64_t limit; +} queues[] = { + { "<0.1ms", NSEC_PER_MILLISEC * 1 / 10 }, + { "<0.2ms", NSEC_PER_MILLISEC * 2 / 10 }, + { "<0.5ms", NSEC_PER_MILLISEC * 5 / 10 }, + { "<1ms", NSEC_PER_MILLISEC * 1 }, + { "<2ms", NSEC_PER_MILLISEC * 2 }, + { "<5ms", NSEC_PER_MILLISEC * 5 }, + { "<10ms", NSEC_PER_MILLISEC * 10 }, + { "<20ms", NSEC_PER_MILLISEC * 20 }, + { "<50ms", NSEC_PER_MILLISEC * 50 }, + { ">50ms", INT64_MAX } +}; +#define NUM_QUEUE G_N_ELEMENTS(queues) + +static uint64_t queue_counts[NUM_QUEUE]; +static uint64_t queue_total_count = 0; +static uint64_t queue_total_time = 0; +static uint64_t queue_min = UINT64_MAX, queue_max = 0; + +static inline void queue_pipe_init(RedPipeItem *item) +{ + item->time_added = spice_get_monotonic_time_ns(); +} + +static void queue_pipe_add(const RedPipeItem *item) +{ + spice_assert(item->time_added); + + red_time_t time_ns = spice_get_monotonic_time_ns() - item->time_added; + + queue_total_time += time_ns; + queue_total_count++; + if (queue_max < time_ns) + queue_max = time_ns; + if (queue_min > time_ns) + queue_min = time_ns; + + int i; + for (i = 0; i < NUM_QUEUE; ++i) + if (time_ns < queues[i].limit || i == NUM_QUEUE-1) { + ++queue_counts[i]; + break; + } +} + +void queue_print_stats(void) +{ + const char *sep; + char distribution[256], *p = distribution; + int i; + + for (i = 0, sep = ""; i < NUM_QUEUE; ++i, sep = ", ") + p += sprintf(p, "%s%s=%" PRIu64, sep, queues[i].desc, queue_counts[i]); + +#define TIME_FMT "%gms" +#define TIME_CONV(n) ((double)(n)/NSEC_PER_MILLISEC) + spice_info("avg="TIME_FMT", max="TIME_FMT", min="TIME_FMT" (n=%"PRIu64") queue time distribution: %s", + TIME_CONV(queue_total_time / queue_total_count), + TIME_CONV(queue_max), TIME_CONV(queue_min), + queue_total_count, + distribution); +} +#else +static inline void queue_pipe_add(const RedPipeItem *item) {} +static inline void queue_pipe_init(RedPipeItem *item) {} +#endif + void RedChannelClient::send_any_item(RedPipeItem *item) { + queue_pipe_add(item); + spice_assert(no_item_being_sent()); priv->reset_send_data(); switch (item->type) { @@ -1381,6 +1455,7 @@ inline bool RedChannelClient::prepare_pipe_add(RedPipeItem *item) if (priv->pipe.empty()) { priv->watch_update_mask(SPICE_WATCH_EVENT_READ | SPICE_WATCH_EVENT_WRITE); } + queue_pipe_init(item); return true; } diff --git a/server/red-channel.h b/server/red-channel.h index 60fef188..c4fd8a1d 100644 --- a/server/red-channel.h +++ b/server/red-channel.h @@ -202,6 +202,12 @@ inline RedChannel::CreationFlags operator|(RedChannel::CreationFlags a, RedChann #define red_channel_message(...) red_channel_log_generic(g_message, __VA_ARGS__) #define red_channel_debug(...) red_channel_log_generic(g_debug, __VA_ARGS__) +#ifdef QUEUE_STAT +void queue_print_stats(void); +#else +static inline void queue_print_stats(void) {} +#endif + #include "pop-visibility.h" #endif /* RED_CHANNEL_H_ */ diff --git a/server/red-pipe-item.h b/server/red-pipe-item.h index 10e5a12c..5ae77647 100644 --- a/server/red-pipe-item.h +++ b/server/red-pipe-item.h @@ -62,6 +62,10 @@ struct RedPipeItem: public red::shared_ptr_counted const int type; void add_to_marshaller(SpiceMarshaller *m, uint8_t *data, size_t size); + +#ifdef QUEUE_STAT + red_time_t time_added; +#endif }; typedef red::shared_ptr<RedPipeItem> RedPipeItemPtr; |