From 7b1d03508da0f2f9db2b042e3cc9f34cbdd7a56b Mon Sep 17 00:00:00 2001 From: Marc-André Lureau Date: Tue, 17 Sep 2013 03:39:25 +0200 Subject: worker: move RED_WORKER_STAT, make it compile again MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Acked-by: Fabiano Fidêncio --- server/display-channel.h | 9 +- server/red_worker.c | 222 ++++++++++++----------------------------------- server/stat.h | 92 +++++++++++++++++++- 3 files changed, 154 insertions(+), 169 deletions(-) diff --git a/server/display-channel.h b/server/display-channel.h index 42574a12..1403b33f 100644 --- a/server/display-channel.h +++ b/server/display-channel.h @@ -315,6 +315,14 @@ struct DisplayChannel { ImageCache image_cache; RedCompressBuf *free_compress_bufs; +/* TODO: some day unify this, make it more runtime.. */ +#ifdef RED_WORKER_STAT + stat_info_t add_stat; + stat_info_t exclude_stat; + stat_info_t __exclude_stat; + uint32_t add_count; + uint32_t add_with_shadow_count; +#endif #ifdef RED_STATISTICS uint64_t *cache_hits_counter; uint64_t *add_to_cache_counter; @@ -440,5 +448,4 @@ static inline int is_primary_surface(DisplayChannel *display, uint32_t surface_i return FALSE; } - #endif /* DISPLAY_CHANNEL_H_ */ diff --git a/server/red_worker.c b/server/red_worker.c index ec1edb14..f96ffba1 100644 --- a/server/red_worker.c +++ b/server/red_worker.c @@ -68,7 +68,6 @@ //#define COMPRESS_STAT //#define DUMP_BITMAP -//#define RED_WORKER_STAT //#define COMPRESS_DEBUG #define CMD_RING_POLL_TIMEOUT 10 //milli @@ -110,102 +109,6 @@ static void rendering_incorrect(const char *msg) spice_warning("rendering incorrect from now on: %s", msg); } -typedef unsigned long stat_time_t; - -#if defined(RED_WORKER_STAT) || defined(COMPRESS_STAT) -double stat_cpu_time_to_sec(stat_time_t time) -{ - return (double)time / (1000 * 1000 * 1000); -} - -typedef struct stat_info_s { - const char *name; - uint32_t count; - stat_time_t max; - stat_time_t min; - stat_time_t total; -#ifdef COMPRESS_STAT - uint64_t orig_size; - uint64_t comp_size; -#endif -} stat_info_t; - -static inline void stat_reset(stat_info_t *info) -{ - info->count = info->max = info->total = 0; - info->min = ~(stat_time_t)0; -#ifdef COMPRESS_STAT - info->orig_size = info->comp_size = 0; -#endif -} - -#endif - -#ifdef RED_WORKER_STAT -static const char *add_stat_name = "add"; -static const char *exclude_stat_name = "exclude"; -static const char *__exclude_stat_name = "__exclude"; - -static inline void stat_init(stat_info_t *info, const char *name) -{ - info->name = name; - stat_reset(info); -} - -static inline void stat_add(struct RedWorker *worker, stat_info_t *info, stat_time_t start) -{ - stat_time_t time; - ++info->count; - time = stat_now(worker) - start; - info->total += time; - info->max = MAX(info->max, time); - info->min = MIN(info->min, time); -} - -#else -#define stat_add(a, b) -#define stat_init(a, b) -#endif - -#ifdef COMPRESS_STAT -static const char *lz_stat_name = "lz"; -static const char *glz_stat_name = "glz"; -static const char *quic_stat_name = "quic"; -static const char *jpeg_stat_name = "jpeg"; -static const char *zlib_stat_name = "zlib_glz"; -static const char *jpeg_alpha_stat_name = "jpeg_alpha"; -static const char *lz4_stat_name = "lz4"; - -static inline void stat_compress_init(stat_info_t *info, const char *name) -{ - info->name = name; - stat_reset(info); -} - -static inline void stat_compress_add(struct RedWorker *worker, stat_info_t *info, - stat_time_t start, int orig_size, - int comp_size) -{ - stat_time_t time; - ++info->count; - time = stat_now(worker) - start; - info->total += time; - info->max = MAX(info->max, time); - info->min = MIN(info->min, time); - info->orig_size += orig_size; - info->comp_size += comp_size; -} - -static inline double stat_byte_to_mega(uint64_t size) -{ - return (double)size / (1000 * 1000); -} - -#else -#define stat_compress_init(a, b) -#define stat_compress_add(a, b, c, d) -#endif - #define MAX_EVENT_SOURCES 20 #define INF_EVENT_WAIT ~0 @@ -379,13 +282,6 @@ typedef struct RedWorker { ZlibEncoder *zlib; uint32_t process_commands_generation; -#ifdef RED_WORKER_STAT - stat_info_t add_stat; - stat_info_t exclude_stat; - stat_info_t __exclude_stat; - uint32_t add_count; - uint32_t add_with_shadow_count; -#endif #ifdef RED_STATISTICS StatNodeRef stat; uint64_t *wakeup_counter; @@ -413,15 +309,6 @@ typedef struct BitmapData { static inline int validate_surface(RedWorker *worker, uint32_t surface_id); -static stat_time_t stat_now(RedWorker *worker) -{ - clockid_t clock_id = worker->clockid; - struct timespec ts; - - clock_gettime(clock_id, &ts); - return ts.tv_nsec + ts.tv_sec * 1000 * 1000 * 1000; -} - static void red_draw_qxl_drawable(RedWorker *worker, Drawable *drawable); static void red_current_flush(RedWorker *worker, int surface_id); static void red_draw_drawable(RedWorker *worker, Drawable *item); @@ -1347,7 +1234,7 @@ static inline void __exclude_region(RedWorker *worker, Ring *ring, TreeItem *ite { QRegion and_rgn; #ifdef RED_WORKER_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif region_clone(&and_rgn, rgn); @@ -1410,14 +1297,14 @@ static inline void __exclude_region(RedWorker *worker, Ring *ring, TreeItem *ite } } region_destroy(&and_rgn); - stat_add(&worker->__exclude_stat, start_time); + stat_add(&worker->display_channel->__exclude_stat, start_time); } static void exclude_region(RedWorker *worker, Ring *ring, RingItem *ring_item, QRegion *rgn, TreeItem **last, Drawable *frame_candidate) { #ifdef RED_WORKER_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif Ring *top_ring; @@ -1454,7 +1341,7 @@ static void exclude_region(RedWorker *worker, Ring *ring, RingItem *ring_item, Q } if (region_is_empty(rgn)) { - stat_add(&worker->exclude_stat, start_time); + stat_add(&worker->display_channel->exclude_stat, start_time); return; } } @@ -1462,7 +1349,7 @@ static void exclude_region(RedWorker *worker, Ring *ring, RingItem *ring_item, Q while ((last && *last == (TreeItem *)ring_item) || !(ring_item = ring_next(ring, ring_item))) { if (ring == top_ring) { - stat_add(&worker->exclude_stat, start_time); + stat_add(&worker->display_channel->exclude_stat, start_time); return; } ring_item = &container->base.siblings_link; @@ -2387,7 +2274,7 @@ static inline int red_current_add(RedWorker *worker, Ring *ring, Drawable *drawa { DrawItem *item = &drawable->tree_item; #ifdef RED_WORKER_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif RingItem *now; QRegion exclude_rgn; @@ -2413,7 +2300,7 @@ static inline int red_current_add(RedWorker *worker, Ring *ring, Drawable *drawa if (!(test_res & REGION_TEST_RIGHT_EXCLUSIVE) && !(test_res & REGION_TEST_LEFT_EXCLUSIVE) && red_current_add_equal(worker, item, sibling)) { - stat_add(&worker->add_stat, start_time); + stat_add(&worker->display_channel->add_stat, start_time); return FALSE; } @@ -2498,7 +2385,7 @@ static inline int red_current_add(RedWorker *worker, Ring *ring, Drawable *drawa } } region_destroy(&exclude_rgn); - stat_add(&worker->add_stat, start_time); + stat_add(&worker->display_channel->add_stat, start_time); return TRUE; } @@ -2515,8 +2402,8 @@ static inline int red_current_add_with_shadow(RedWorker *worker, Ring *ring, Dra { DisplayChannel *display = worker->display_channel; #ifdef RED_WORKER_STAT - stat_time_t start_time = stat_now(worker); - ++worker->add_with_shadow_count; + stat_time_t start_time = stat_now(worker->clockid); + ++display->add_with_shadow_count; #endif RedDrawable *red_drawable = item->red_drawable; @@ -2527,7 +2414,7 @@ static inline int red_current_add_with_shadow(RedWorker *worker, Ring *ring, Dra Shadow *shadow = shadow_new(&item->tree_item, &delta); if (!shadow) { - stat_add(&worker->add_stat, start_time); + stat_add(&display->add_stat, start_time); return FALSE; } // item and his shadow must initially be placed in the same container. @@ -2551,7 +2438,7 @@ static inline int red_current_add_with_shadow(RedWorker *worker, Ring *ring, Dra detach_streams_behind(display, &item->tree_item.base.rgn, item); } } - stat_add(&worker->add_stat, start_time); + stat_add(&display->add_stat, start_time); return TRUE; } @@ -2599,31 +2486,29 @@ static void drawable_update_streamable(DisplayChannel *display, Drawable *drawab drawable->streamable = TRUE; } -static void red_print_stats(RedWorker *worker) +void print_stats(DisplayChannel *display) { #ifdef RED_WORKER_STAT - if ((++worker->add_count % 100) == 0) { - stat_time_t total = worker->add_stat.total; - spice_info("add with shadow count %u", - worker->add_with_shadow_count); - worker->add_with_shadow_count = 0; - spice_info("add[%u] %f exclude[%u] %f __exclude[%u] %f", - worker->add_stat.count, - stat_cpu_time_to_sec(total), - worker->exclude_stat.count, - stat_cpu_time_to_sec(worker->exclude_stat.total), - worker->__exclude_stat.count, - stat_cpu_time_to_sec(worker->__exclude_stat.total)); - spice_info("add %f%% exclude %f%% exclude2 %f%% __exclude %f%%", - (double)(total - worker->exclude_stat.total) / total * 100, - (double)(worker->exclude_stat.total) / total * 100, - (double)(worker->exclude_stat.total - - worker->__exclude_stat.total) / worker->exclude_stat.total * 100, - (double)(worker->__exclude_stat.total) / worker->exclude_stat.total * 100); - stat_reset(&worker->add_stat); - stat_reset(&worker->exclude_stat); - stat_reset(&worker->__exclude_stat); - } + stat_time_t total = display->add_stat.total; + spice_info("add with shadow count %u", + display->add_with_shadow_count); + display->add_with_shadow_count = 0; + spice_info("add[%u] %f exclude[%u] %f __exclude[%u] %f", + display->add_stat.count, + stat_cpu_time_to_sec(total), + display->exclude_stat.count, + stat_cpu_time_to_sec(display->exclude_stat.total), + display->__exclude_stat.count, + stat_cpu_time_to_sec(display->__exclude_stat.total)); + spice_info("add %f%% exclude %f%% exclude2 %f%% __exclude %f%%", + (double)(total - display->exclude_stat.total) / total * 100, + (double)(display->exclude_stat.total) / total * 100, + (double)(display->exclude_stat.total - + display->__exclude_stat.total) / display->exclude_stat.total * 100, + (double)(display->__exclude_stat.total) / display->exclude_stat.total * 100); + stat_reset(&display->add_stat); + stat_reset(&display->exclude_stat); + stat_reset(&display->__exclude_stat); #endif } @@ -2641,7 +2526,10 @@ static int red_add_drawable(RedWorker *worker, Drawable *drawable) ret = red_current_add(worker, ring, drawable); } - red_print_stats(worker); +#ifdef RED_WORKER_STAT + if ((++display->add_count % 100) == 0) + print_stats(display); +#endif return ret; } @@ -3428,7 +3316,7 @@ static int red_process_commands(RedWorker *worker, uint32_t max_pipe_size, int * if (worker->record_fd) red_record_qxl_command(worker->record_fd, &worker->mem_slots, ext_cmd, - stat_now(worker)); + stat_now(worker->clockid)); stat_inc_counter(worker->command_counter, 1); worker->display_poll_tries = 0; @@ -4318,7 +4206,7 @@ static inline int red_glz_compress_image(DisplayChannelClient *dcc, DisplayChannel *display_channel = DCC_TO_DC(dcc); RedWorker *worker = display_channel->common.worker; #ifdef COMPRESS_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif spice_assert(bitmap_fmt_is_rgb(src->format)); GlzData *glz_data = &dcc->glz_data; @@ -4361,7 +4249,7 @@ static inline int red_glz_compress_image(DisplayChannelClient *dcc, goto glz; } #ifdef COMPRESS_STAT - start_time = stat_now(worker); + start_time = stat_now(worker->clockid); #endif zlib_data = &worker->zlib_data; @@ -4424,7 +4312,7 @@ static inline int red_lz_compress_image(DisplayChannelClient *dcc, int size; // size of the compressed data #ifdef COMPRESS_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif lz_data->data.bufs_tail = red_display_alloc_compress_buf(dcc); @@ -4510,7 +4398,7 @@ static int red_jpeg_compress_image(DisplayChannelClient *dcc, SpiceImage *dest, uint8_t *lz_out_start_byte; #ifdef COMPRESS_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif switch (src->format) { case SPICE_BITMAP_FMT_16BIT: @@ -4644,7 +4532,7 @@ static int red_lz4_compress_image(DisplayChannelClient *dcc, SpiceImage *dest, int lz4_size = 0; #ifdef COMPRESS_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif lz4_data->data.bufs_tail = red_display_alloc_compress_buf(dcc); @@ -4710,7 +4598,7 @@ static inline int red_quic_compress_image(DisplayChannelClient *dcc, SpiceImage int size, stride; #ifdef COMPRESS_STAT - stat_time_t start_time = stat_now(worker); + stat_time_t start_time = stat_now(worker->clockid); #endif switch (src->format) { @@ -8699,6 +8587,9 @@ static void display_channel_create(RedWorker *worker, int migrate) return; } worker->display_channel = display_channel; + stat_init(&display_channel->add_stat, "add", worker->clockid); + stat_init(&display_channel->exclude_stat, "exclude", worker->clockid); + stat_init(&display_channel->__exclude_stat, "__exclude", worker->clockid); #ifdef RED_STATISTICS RedChannel *channel = RED_CHANNEL(display_channel); display_channel->cache_hits_counter = stat_add_counter(channel->stat, @@ -8708,13 +8599,13 @@ static void display_channel_create(RedWorker *worker, int migrate) display_channel->non_cache_counter = stat_add_counter(channel->stat, "non_cache", TRUE); #endif - stat_compress_init(&display_channel->lz_stat, lz_stat_name); - stat_compress_init(&display_channel->glz_stat, glz_stat_name); - stat_compress_init(&display_channel->quic_stat, quic_stat_name); - stat_compress_init(&display_channel->jpeg_stat, jpeg_stat_name); - stat_compress_init(&display_channel->zlib_glz_stat, zlib_stat_name); - stat_compress_init(&display_channel->jpeg_alpha_stat, jpeg_alpha_stat_name); - stat_compress_init(&display_channel->lz4_stat, lz4_stat_name); + stat_compress_init(&display_channel->lz_stat, "lz"); + stat_compress_init(&display_channel->glz_stat, "glz"); + stat_compress_init(&display_channel->quic_stat, "quic"); + stat_compress_init(&display_channel->jpeg_stat, "jpeg"); + stat_compress_init(&display_channel->zlib_glz_stat, "zlib"); + stat_compress_init(&display_channel->jpeg_alpha_stat, "jpeg_alpha"); + stat_compress_init(&display_channel->lz4_stat, "lz4"); display_channel->num_renderers = num_renderers; memcpy(display_channel->renderers, renderers, sizeof(display_channel->renderers)); @@ -9626,7 +9517,7 @@ static void worker_dispatcher_record(void *opaque, uint32_t message_type, void * { RedWorker *worker = opaque; - red_record_event(worker->record_fd, 1, message_type, stat_now(worker)); + red_record_event(worker->record_fd, 1, message_type, stat_now(worker->clockid)); } static void register_callbacks(Dispatcher *dispatcher) @@ -9848,9 +9739,6 @@ RedWorker* red_worker_new(QXLInstance *qxl, RedDispatcher *red_dispatcher) worker->zlib_glz_state = zlib_glz_state; worker->driver_cap_monitors_config = 0; image_surface_init(worker); - stat_init(&worker->add_stat, add_stat_name); - stat_init(&worker->exclude_stat, exclude_stat_name); - stat_init(&worker->__exclude_stat, __exclude_stat_name); #ifdef RED_STATISTICS char worker_str[20]; sprintf(worker_str, "display[%d]", worker->qxl->id); diff --git a/server/stat.h b/server/stat.h index d5c18781..52e6e781 100644 --- a/server/stat.h +++ b/server/stat.h @@ -24,7 +24,6 @@ typedef uint32_t StatNodeRef; #define INVALID_STAT_REF (~(StatNodeRef)0) #ifdef RED_STATISTICS - StatNodeRef stat_add_node(StatNodeRef parent, const char *name, int visible); void stat_remove_node(StatNodeRef node); uint64_t *stat_add_counter(StatNodeRef parent, const char *name, int visible); @@ -42,6 +41,97 @@ void stat_remove_counter(uint64_t *counter); #define stat_add_counter(p, n, v) NULL #define stat_remove_counter(c) #define stat_inc_counter(c, v) +#endif /* RED_STATISTICS */ + +typedef unsigned long stat_time_t; + +static inline stat_time_t stat_now(clockid_t clock_id) +{ + struct timespec ts; + + clock_gettime(clock_id, &ts); + return ts.tv_nsec + ts.tv_sec * 1000 * 1000 * 1000; +} + +static inline double stat_cpu_time_to_sec(stat_time_t time) +{ + return (double)time / (1000 * 1000 * 1000); +} + +typedef struct stat_info_s { + const char *name; + clockid_t clock; + uint32_t count; + stat_time_t max; + stat_time_t min; + stat_time_t total; +#ifdef COMPRESS_STAT + uint64_t orig_size; + uint64_t comp_size; #endif +} stat_info_t; +static inline void stat_reset(stat_info_t *info) +{ + info->count = info->max = info->total = 0; + info->min = ~(stat_time_t)0; +#ifdef COMPRESS_STAT + info->orig_size = info->comp_size = 0; #endif +} + +#ifdef COMPRESS_STAT +static inline void stat_compress_init(stat_info_t *info, const char *name) +{ + info->name = name; + stat_reset(info); +} + +static inline void stat_compress_add(RedWorker *worker, stat_info_t *info, + stat_time_t start, int orig_size, + int comp_size) +{ + stat_time_t time; + ++info->count; + time = stat_now(worker) - start; + info->total += time; + info->max = MAX(info->max, time); + info->min = MIN(info->min, time); + info->orig_size += orig_size; + info->comp_size += comp_size; +} + +double inline stat_byte_to_mega(uint64_t size) +{ + return (double)size / (1000 * 1000); +} + +#else +#define stat_compress_init(a, b) +#define stat_compress_add(a, b, c, d) +#endif + +#ifdef RED_WORKER_STAT +static inline void stat_init(stat_info_t *info, const char *name, clockid_t clock) +{ + info->name = name; + info->clock = clock; + stat_reset(info); +} + +static inline void stat_add(stat_info_t *info, stat_time_t start) +{ + stat_time_t time; + ++info->count; + time = stat_now(info->clock) - start; + info->total += time; + info->max = MAX(info->max, time); + info->min = MIN(info->min, time); +} + +#else +#define stat_add(a, b) +#define stat_init(a, b, c) +#endif /* RED_WORKER_STAT */ + +#endif /* _H_STAT */ -- cgit