bench.c 7.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282
  1. #ifdef HAVE_CONFIG_H
  2. #include "config.h"
  3. #endif
  4. #include <log4c/defs.h>
  5. #include <log4c/appender.h>
  6. #include <log4c/category.h>
  7. #include <log4c/init.h>
  8. #include <log4c/appender_type_stream2.h>
  9. #include <sd/malloc.h>
  10. #include <stdio.h>
  11. #include <stdlib.h>
  12. #include <string.h>
  13. #ifdef HAVE_SYS_TIME_H
  14. #include <sys/time.h>
  15. #endif
  16. #ifdef HAVE_UNISTD_H
  17. #include <unistd.h>
  18. #endif
  19. #include <sd/sd_xplatform.h>
  20. /******************************************************************************/
  21. typedef XP_UINT64 usec_t;
  22. static usec_t my_utime(void)
  23. {
  24. #if defined(_WIN32) && !defined(__MINGW32__) && !defined(__MINGW64__)
  25. FILETIME tv;
  26. ULARGE_INTEGER li;
  27. #else
  28. struct timeval tv;
  29. #endif
  30. SD_GETTIMEOFDAY(&tv, NULL);
  31. #if defined(_WIN32) && !defined(__MINGW32__) && !defined(__MINGW64__)
  32. memcpy(&li, &tv, sizeof(FILETIME));
  33. li.QuadPart /= 10; /* In microseconds */
  34. /* printf("timestampstamp usec %I64u\n", li.QuadPart);*/
  35. return li.QuadPart;
  36. #else
  37. return (usec_t) (tv.tv_sec * 1000000 + tv.tv_usec);
  38. #endif
  39. }
  40. /******************************************************************************/
  41. #define MSG_SIZE 128
  42. #define NUM_MSGS 16
  43. #if defined(_WIN32)
  44. #define display_time(name,start,stop,elapsed, avg) \
  45. fprintf(stderr,"%s: (start %I64u stop %I64u) elapsed %I64u us - average %I64u us\n\n", \
  46. name, start, stop, elapsed, avg)
  47. #else
  48. #define display_time(name,start,stop,elapsed, avg) \
  49. fprintf(stderr,"%s: (start %llu stop %llu) elapsed %llu us - average %llu us\n\n", \
  50. name,start, stop, elapsed, avg)
  51. #endif
  52. #define USAGE "Usage: bench [-n] [-h] <num msgs> [<msg size>]\n\n" \
  53. "This program runs a sequence of timed calls to log4c logging calls.\n" \
  54. "This allows, for example, the performance of different appenders\n" \
  55. "or the performance of a given appender with different options to be\n" \
  56. "compared.\n\n" \
  57. "The results are sent to stderr so you can collect them in a file by doing\n" \
  58. "something like this: './bench 128 2> results.txt'\n\n" \
  59. "For covenience, we allow the appenders that write to the screen to be\n" \
  60. "turned off using the -n option. By default they are run.\n\n" \
  61. "The default msg size is 128.\n\n" \
  62. "-n do not run the timed tests that write to the screen\n" \
  63. "-h display this help message\n"
  64. /******************************************************************************/
  65. int g_doall = 0;
  66. int g_noscreen_appenders = 0;
  67. long g_num_msgs = NUM_MSGS;
  68. long g_msgsize = MSG_SIZE;
  69. static log4c_category_t* catmmap = NULL;
  70. static log4c_category_t* catstream = NULL;
  71. static log4c_category_t* catstream2 = NULL;
  72. static log4c_category_t* catstream_file = NULL;
  73. /******************************************************************************/
  74. void getopts(int argc, char **argv){
  75. char c;
  76. if ( argc == 1) {
  77. fprintf(stderr,USAGE);
  78. exit(1);
  79. }
  80. while ((c = SD_GETOPT(argc, argv, "nh")) != -1) {
  81. switch(c) {
  82. case 'n':
  83. g_noscreen_appenders = 1;
  84. break;
  85. case 'h':
  86. fprintf(stderr, USAGE);
  87. exit(1);
  88. break;
  89. }
  90. }
  91. /* Pick up the number of msgs and the size */
  92. if ( SD_OPTIND < argc ){
  93. g_num_msgs = atol(argv[SD_OPTIND]);
  94. if ( SD_OPTIND+1 < argc ){
  95. g_msgsize = atol(argv[SD_OPTIND+1]);
  96. }
  97. }
  98. fprintf(stderr, " Writing %ld message(s) of length %ld\n",
  99. g_num_msgs,g_msgsize);
  100. if ( g_noscreen_appenders){
  101. fprintf(stderr, " Not running tests that log to the screen\n\n");
  102. }
  103. }
  104. int main(int argc, char* argv[]){
  105. int flags = 0;
  106. char* buffer = NULL;
  107. int i;
  108. usec_t start;
  109. usec_t stop;
  110. char *test_name;
  111. /* declare and get a reference to some unconfigured appenders */
  112. log4c_appender_t* mmap_appender = log4c_appender_get("bench.mmap");
  113. log4c_appender_t* stream_appender = log4c_appender_get("stdout");
  114. log4c_appender_t* stream2_appender = log4c_appender_get("bench.stream2");
  115. log4c_appender_t* streamfile_appender = log4c_appender_get("bench.stream");
  116. /*
  117. * Obligatory log4c init call
  118. */
  119. log4c_init();
  120. /*
  121. * Get some categories
  122. */
  123. catmmap = log4c_category_get("mmap");
  124. catstream = log4c_category_get("stream");
  125. catstream2 = log4c_category_get("stream2");
  126. catstream_file = log4c_category_get("stream_file");
  127. /*
  128. * Read command line options
  129. */
  130. getopts(argc, argv);
  131. /*
  132. * Configure the categories and appenders
  133. */
  134. log4c_appender_set_type(mmap_appender, log4c_appender_type_get("mmap"));
  135. log4c_category_set_appender(catmmap, mmap_appender);
  136. log4c_category_set_appender(catstream, stream_appender);
  137. log4c_appender_set_type(stream2_appender,
  138. log4c_appender_type_get("stream2"));
  139. log4c_category_set_appender(catstream2, stream2_appender);
  140. log4c_category_set_appender(catstream_file, streamfile_appender);
  141. log4c_category_set_priority(log4c_category_get("root"),
  142. LOG4C_PRIORITY_ERROR);
  143. /*
  144. * Get a buffer for the message
  145. */
  146. buffer = (char*) malloc(g_msgsize * sizeof(char));
  147. memset(buffer, 'X', g_msgsize);
  148. buffer[g_msgsize - 1] = '\0';
  149. /*
  150. * Calibration: do a couple of 1 second sleeps to make sure
  151. * the timing routines are in working order.
  152. */
  153. start = my_utime();
  154. for (i = 0; i < 2; i++){ sleep(1);}
  155. stop = my_utime();
  156. display_time("calibration 2 x 1 second sleep calls", start, stop, (stop-start), (stop-start)/2);
  157. /* logs that write to the screen, if required */
  158. if ( !g_noscreen_appenders){
  159. /*
  160. * fprintf writing to the screen
  161. */
  162. start = my_utime();
  163. for (i = 0; i < g_num_msgs; i++){ fprintf(stdout, "%s\n", buffer);}
  164. stop = my_utime();
  165. display_time("fprintf", start, stop, (stop-start), (stop-start)/g_num_msgs);
  166. /*
  167. * log4c writing to the screen
  168. */
  169. start = my_utime();
  170. for (i = 0; i < g_num_msgs; i++){
  171. log4c_category_error(catstream, "%s", buffer);
  172. }
  173. stop = my_utime();
  174. display_time("fprintf", start, stop, (stop-start),
  175. (stop-start)/g_num_msgs);
  176. }
  177. /* Logs that write to files */
  178. /*
  179. * mmap appender writing to bench.mmap
  180. *
  181. * On windows as this type is not implemented it makes pretty much
  182. * null calls to log4c--so it does nothing but is safe.
  183. */
  184. start = my_utime();
  185. for (i = 0; i < g_num_msgs; i++){ log4c_category_error(catmmap, "%s", buffer);}
  186. stop = my_utime();
  187. display_time("mmap", start, stop, (stop-start),
  188. (stop-start)/g_num_msgs);
  189. /*
  190. * stream appender writing to bench.stream
  191. */
  192. start = my_utime();
  193. for (i = 0; i < g_num_msgs; i++){
  194. log4c_category_error(catstream_file, "%s", buffer);
  195. }
  196. stop = my_utime();
  197. display_time("stream_file", start, stop, (stop-start),
  198. (stop-start)/g_num_msgs);
  199. /*
  200. * stream2 appender writing to bench.stream2
  201. * in buffered mode
  202. */
  203. log4c_appender_open(stream2_appender);
  204. flags = log4c_stream2_get_flags(stream2_appender);
  205. start = my_utime();
  206. for (i = 0; i < g_num_msgs; i++){
  207. log4c_category_error(catstream2, "%s", buffer);
  208. }
  209. stop = my_utime();
  210. test_name = (flags & LOG4C_STREAM2_UNBUFFERED ?
  211. "stream2 unbuffered -":"stream2 buffered -");
  212. display_time(test_name,start, stop, (stop-start),(stop-start)/g_num_msgs);
  213. log4c_appender_close(stream2_appender);
  214. /*
  215. * stream2 appender writing to bench.stream2
  216. * in unbuffered mode -- for comparison with buffered mode
  217. * test above
  218. */
  219. log4c_appender_open(stream2_appender);
  220. log4c_stream2_set_flags(stream2_appender, LOG4C_STREAM2_UNBUFFERED);
  221. flags = log4c_stream2_get_flags(stream2_appender);
  222. start = my_utime();
  223. for (i = 0; i < g_num_msgs; i++){
  224. log4c_category_error(catstream2, "%s", buffer);
  225. }
  226. stop = my_utime();
  227. display_time((flags & LOG4C_STREAM2_UNBUFFERED ? "stream2 unbuffered -":"stream2 buffered -"),
  228. start, stop, (stop-start),(stop-start)/g_num_msgs);
  229. log4c_appender_close(stream2_appender);
  230. /*
  231. * Obligatory log4c cleanup call
  232. */
  233. log4c_fini();
  234. free(buffer);
  235. return 0;
  236. }