From 9727692a83a1ba16870dd1cdbf0e25b5dbede129 Mon Sep 17 00:00:00 2001 From: gabi Date: Sat, 25 Jan 2014 17:28:56 +0200 Subject: [PATCH] async_sink --- c11log.sln | 5 +- c11log.v12.suo | Bin 32768 -> 36864 bytes include/c11log/sinks/async_sink.h | 84 +++++++++++++++++------------- include/c11log/sinks/file_sinks.h | 2 +- test/test.cpp | 27 +++++++--- test/utils.h | 15 +++++- 6 files changed, 85 insertions(+), 48 deletions(-) diff --git a/c11log.sln b/c11log.sln index 582ead83..12cf0eaf 100644 --- a/c11log.sln +++ b/c11log.sln @@ -1,7 +1,7 @@  Microsoft Visual Studio Solution File, Format Version 12.00 # Visual Studio 2013 -VisualStudioVersion = 12.0.21005.1 +VisualStudioVersion = 12.0.30110.0 MinimumVisualStudioVersion = 10.0.40219.1 Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "c11log", "c11log.vcxproj", "{BBFA8622-1945-4EB0-BAF4-473BE753ED24}" EndProject @@ -28,4 +28,7 @@ Global GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE EndGlobalSection + GlobalSection(Performance) = preSolution + HasPerformanceSessions = true + EndGlobalSection EndGlobal diff --git a/c11log.v12.suo b/c11log.v12.suo index da81938b34f00b12e03a566f4387bffde5c6522c..e9581de907b7f73a537e1011402486a341d8ce97 100644 GIT binary patch delta 4039 zcmcImYfxLq72cI4kU(I-!hjJV9ySJqEMcBD7=eWRAQ;&w*r|h!fC~r&!qU|QjAMz| z@uR_Y(CNc%)5gK+c$!JmU^#uJEot(jZDwNXag%l?o+NJCOxr(cC;owFT6)e!7t`38 z>5pVJpZ4t8vuF1__UsLZ72!*Yr_DJ`ZYhjyL|TFP&(hKou{lgBv*)@m@`&Ogu7!L> zUh=|UKdOE|>pCyS>2L`gQyk;pgFA}78m>pqdIY?t-^`zf;F@+ds#!{kv69Xpp+!*3 z1Fp;tB_c&4a@!OeXMT#GhT{z}Ug4+abg^+$tdEcNbeeobDxv_9iy*V;I4VRDu{I-7 zil74+V|_XHCPXdSKGUt`4M?m@+JUS_gcV@`o{<4ArEaGCW+ZMTsqo>G@1aY!(DbrP zo{!#%TgOA$$oV(wrj4ns#WD5d1|=drHcp836bv<@3?UmWuU&_{EJPfFbR=WH9Z?b+ z%W^bFMq>wOl<70wY7ItKT9N@jP}}(WWy3y+B%I}!qf-fw@k(0z1PYx*oI*T_AfAkK zIQ}x?sTluj*h6K4q3P>Ld;@V2@lC|H5Z^{TgZK`D6g(U2pNsXEW4)w&Zr?D!nru_R z>l+#%oGhyHaP~u3Ob+n{m`J?>23?_sQDTtKD78S;EvOARpolIr(w*>z!W{i1-K2n` z5`A<>MI2XCG$^LaBKb}=X{NvuLv;a(qp(=K2VPfLz^qWh_~r#ACFHVvlS@g7A;}&_ zVkWwn+RkC$4kL)`UIc^TGA)do!YLJpyA^vLydMRebZDjha6oM~R}rz=rOQE=4d;!~ zajTQB?5LG?lw=u;IP7XldP;0k6&0Q5IlQ88j9T@DJf(I2m~i8rM^5f!e%&jT=Nn;8 z-v;wJRtW18A+g|(DWR;7hL|VsRK*MDew%yf_TMD|YvFAu$jsMpjL(uKrdf3fi7r^w zmGC;e>p5V}tW?b+ZvcLu*$QuDz8WzU;IhM!^a5F8gIY;9kPc>%L~%f^g^jZ@=4S#6 z;LpQ+Y?PHFw~Ey=8>?VV)Z-@EU_GFeTp@?1VH%eYlVh;$V=i3kV_sC^VnI|i#+=N} zdf71k51@Jzvm+%UT5&W1b8R-&SzNgUi-l5fqoN4|hrv>P7uiRmizQF+lt)iIWxXN{ z-hR@3^Tnety?PU!QU&v6*2pfq+Kgg!$;hV2VP$muOK(c+K`gqiVU;*T*EKc^;~QH^ zxmHq+d}^~N6tmTetDSZZ_O)gZi>I&dvT+Tkt15?)7eO#Pq@u{GVR4H!2Q&kx)k$o8lD_m&lzEbX`|hA&&|S3GlrT zY{RF3>etp7PuqqBX`n{QY{0$%A!($W?STo$q-qaRr(x02s?I=)o&f1ARM!&}aBSyZ zB~?7)VNl2%sjW_s|4oclX#uH}XB(9ijjdr^M~?%wPS%0x)WY^N2lh>vnXUN06FD6c zI@oU3&h}!SX7N&J+Fip9_pX8=YDn8GmxSra`Y}6|Z@FX|kf!&CER}imyb@iE{bmH^ z163Jvmn;L<*4OJAkg)?HKR7fA$_#^^h*q3nm!f;v28phVb^_~L?l*80by_dR-(JSVZ)GeJzo^>fSgUF!L-h<3` zxKNXZYUycokXqQ=SIP$^@sM7Ngj6a7|?9dhE zjW9nnKii#lIXtX@x%zZ?r#3lSDBg;Ph<97`XCt+|ZFyM*Gh=;h!No0jk8D^uEl5|h z8l);&9o|&pH6h1={Bo3T#yK;h1$ou@Ux}j%Xc#Vme~s$bV9>~5#dZc$_4T-UE1gZ^R^=O@#B+rbBm?vs{e5wpUF7o z0-SoRo^#-hCF!(=&O*Jsp21SX6u#jJfUl~G7W9F;G#%#M$?$$}DYWKf;@e+?d}`E_ z@eYKn0d?n6LbAn5jXh`~OO&$JIok2vA-`Md#>%QJ?5LC=`e-8<|a5R8US!5{GWMjI>@CNuqv z1{)d@^a~B6LQwR(y+(sG*yHu|whE|YSQu>x^_aKzSM}HQTP%H5X7^UNiq6sS8QZ(i z6A#|o)DiSKJYK=>7Tu&Fzn)|}VqT+}9m7YCG~+?hiw=+A?c-!;LNk7hYrQ`bclZ3 z+GrRF^!of>PtQGXRsO%u>Zz%5SM^p^Tk5t}3g+6nE~Bh`^&xk;1B0Tw$BXg6y+WVc zW?fk4SbQwRYMXCl%bp zNgoXwx!Nd+c)&rwpmT2dtjxbJm|b`-mWba7=@8Bf<1_F%e9C=n(~wrS>Ql~q|M#7< H{N?`wUU9ol delta 1949 zcmaJ>eQZ-z6o2>GkJqi+-rB7j4A#_PMokm6#55VA$hOduu#>R)O!LU4&2p40BlF{h_Fedp_* z`@83!dz2%*qVR797xLT`i5!=OBI%QN?%W~kJ=*U=9vj&5zG`aE9lf&MH8O96RiPtX z0X=*VJEGk(WiwU@%uur2j`loc0ojO*InsoAxkBW8yoXCRmYSIVR+u2HZStw#T z_+L`I1dS9>j$a?LgltBJQ$om6fC4#l5t^B)re|}$h)%;wWnd){mYucPFmwV#^$iIi zE!9C9P$!=WzXY-f*?~+TDUSBmL6V-0x}J;l8JP2DVkVyzJ{BUg!Db!M2CeN_Ppg`x zOo;_Uxe;EA>nkn@5NvyBR6=qR0b+M5LzD(T8# zw06@T;K5zl3W6^LL0$macLqe?Qj|rMLuxQ$VL@C$=cW8wESO+$${W_gUJnyJn||y* z8TfQz=-ijhw#vU8aMJrQq!x#hrMz0<2JgHD+G>Z9!7yJ9v7%;yt|c&)%G!^@PGlmr z?1reA>c2f2_HBK4xOU#sL}Fz+S-AWz`eno-F!Wy1PXh4lJ6X4c<}FOd4#$iZ*%{g$_wydsFd zUc~K(WM?^4b*`|yKHF+)?}$dXJr8xAm6msAIUULSc?j?F!Jl0f(7$shG`&;=U-hY0 zBPY*}je={}=6o6e8FHlPJ$d2h_+#*Ew+$LQOW|<5!ALh)h1RcaG%y&lJSS2JbZ;o7 zXQ&gUqo*tX-x0Ee%y9xc%He#MbH1+WN%U_qr^XdO!&ah-Wyq0op+K)t?=rGK$32PN z(Zy|rMY3J(2{R7rYpS4<7YC#q$nn)exVPXg7Jbqjt=i0}^NmvtT5smT;H39zFj5T| zT-kpgn0>3zlC3(A!Q>;NXp3LIFfw@cvh#Xz_r(aeL+@bKEerHk7U05k*Sk=#!)|x4 zu@@y7#@&quns&6KX&DM$0eaS~Gti{V^iiFpxmI}aX+2m2@#+_?3(-UOL8LllfeKA? zI1}wqj0aI!2IG#k7LGcS=H7HiQhU;TCWB?VBVi))01Ue^zuahHl-#W^y4liVpt{on z)(2f19)$}_B+DK&r9t39Bbnj!`MIMX1{-dVwcTFuw$J?9_vlFvC)FLHfuzOUZ!lnG z*Z*tqbcl;T`R3B`L&^c=v%#Db_g=e(8S0ZQ{LnI)8PcHB^JsY@xrqm*4o5MT<-JHX zgGe6EJE_ijqfcg-s{38Upfa5^n0kdneG@H|L#dse=l`WvRabF^Wn; diff --git a/include/c11log/sinks/async_sink.h b/include/c11log/sinks/async_sink.h index 5d9a9138..4aee4f76 100644 --- a/include/c11log/sinks/async_sink.h +++ b/include/c11log/sinks/async_sink.h @@ -2,7 +2,6 @@ #include #include -#include #include #include "base_sink.h" @@ -11,39 +10,45 @@ namespace c11log { namespace sinks { -class async_sink : public base_sink { - + +class async_sink : public base_sink +{ public: - using size_type = c11log::details::blocking_queue::size_type; - explicit async_sink(const std::size_t max_queue_size, const std::chrono::seconds& timeout = std::chrono::seconds::max()); + using size_type = c11log::details::blocking_queue::size_type; + + explicit async_sink(const size_type max_queue_size); ~async_sink(); void add_sink(logger::sink_ptr_t sink); - void remove_sink(logger::sink_ptr_t sink_ptr); - + void remove_sink(logger::sink_ptr_t sink_ptr); -protected: + //Wait to remaining items (if any) in the queue to be written and shutdown + void shutdown(const std::chrono::seconds& timeout); + + +protected: void sink_it_(const std::string& msg) override; void thread_loop_(); - -private: + +private: c11log::logger::sinks_vector_t sinks_; - bool active_ = true; - const std::chrono::seconds timeout_; + std::atomic active_ { true }; + const std::chrono::seconds push_pop_timeout_; c11log::details::blocking_queue q_; - std::thread back_thread_; + std::thread back_thread_; + //Clear all remaining messages(if any), stop the back_thread_ and join it void shutdown_(); }; } } -// -// async_sink inline impl -// +/////////////////////////////////////////////////////////////////////////////// +// async_sink class implementation +/////////////////////////////////////////////////////////////////////////////// -inline c11log::sinks::async_sink::async_sink(const std::size_t max_queue_size, const std::chrono::seconds& timeout) +inline c11log::sinks::async_sink::async_sink(const std::size_t max_queue_size) :q_(max_queue_size), - timeout_(timeout), - back_thread_(&async_sink::thread_loop_, this) + push_pop_timeout_(std::chrono::seconds(2)), + back_thread_(&async_sink::thread_loop_, this) {} inline c11log::sinks::async_sink::~async_sink() @@ -52,23 +57,21 @@ inline c11log::sinks::async_sink::~async_sink() } inline void c11log::sinks::async_sink::sink_it_(const std::string& msg) { - q_.push(msg, timeout_); + q_.push(msg, push_pop_timeout_); } inline void c11log::sinks::async_sink::thread_loop_() -{ +{ std::string msg; - while (active_) - { - if (q_.pop(msg, timeout_)) + while (active_) + { + if (q_.pop(msg, push_pop_timeout_)) { - std::lock_guard lock(mutex_); for (auto &sink : sinks_) { - if (active_) - sink->log(msg, _level); - else - break; + sink->log(msg, _level); + if (!active_) + return; } } } @@ -76,23 +79,32 @@ inline void c11log::sinks::async_sink::thread_loop_() inline void c11log::sinks::async_sink::add_sink(logger::sink_ptr_t sink) { - std::lock_guard lock(mutex_); sinks_.push_back(sink); } inline void c11log::sinks::async_sink::remove_sink(logger::sink_ptr_t sink_ptr) { - std::lock_guard lock(mutex_); sinks_.erase(std::remove(sinks_.begin(), sinks_.end(), sink_ptr), sinks_.end()); } + +inline void c11log::sinks::async_sink::shutdown(const std::chrono::seconds &timeout) +{ + auto until = std::chrono::system_clock::now() + timeout; + while (q_.size() > 0 && std::chrono::system_clock::now() < until) + { + std::this_thread::sleep_for(std::chrono::milliseconds(200)); + } + shutdown_(); +} + inline void c11log::sinks::async_sink::shutdown_() { - { - std::lock_guard lock(mutex_); - active_ = false; + if(active_) + { + active_ = false; + if (back_thread_.joinable()) + back_thread_.join(); } - q_.clear(); - back_thread_.join(); } diff --git a/include/c11log/sinks/file_sinks.h b/include/c11log/sinks/file_sinks.h index a8edf5c0..a811dffa 100644 --- a/include/c11log/sinks/file_sinks.h +++ b/include/c11log/sinks/file_sinks.h @@ -125,7 +125,7 @@ private: */ class midnight_file_sink:public details::rotating_file_sink_base { public: - midnight_file_sink(const std::string& base_filename, const std::string& extension): + midnight_file_sink(const std::string& base_filename, const std::string& extension = "txt"): _base_filename(base_filename), _extension(extension), _midnight_tp { _calc_midnight_tp() } diff --git a/test/test.cpp b/test/test.cpp index d6ec4839..dd2b6d34 100644 --- a/test/test.cpp +++ b/test/test.cpp @@ -4,21 +4,32 @@ #include "stdafx.h" -void fn(); + int main(int argc, char* argv[]) { c11log::logger logger("test"); - auto sink = std::make_shared(); - auto async = std::make_shared(100); - async->add_sink(sink); + auto screen_sink = std::make_shared(); + auto file_sink = std::make_shared("logtest"); + auto async = std::make_shared(1000); + async->add_sink(file_sink); logger.add_sink(async); - logger.info() << "Hello logger!"; - utils::run(std::chrono::seconds(10), fn); + //logger.add_sink(file_sink); + + + auto fn = [&logger]() + { + logger.info() << "Hello logger!"; + }; + utils::bench("test log", std::chrono::seconds(3), fn); + logger.info() << "bye"; + utils::bench("shutdown", [&async]() { + async->shutdown(std::chrono::seconds(10)); + }); + + return 0; } -static void fn() -{} diff --git a/test/utils.h b/test/utils.h index c9b56b18..c5210157 100644 --- a/test/utils.h +++ b/test/utils.h @@ -20,7 +20,7 @@ std::string format(const T& value) return ss.str(); } -inline void run(const std::chrono::milliseconds &duration, const std::function& fn) +inline void bench(const std::string& fn_name, const std::chrono::milliseconds &duration, const std::function& fn) { using namespace std::chrono; typedef steady_clock the_clock; @@ -38,10 +38,21 @@ inline void run(const std::chrono::milliseconds &duration, const std::function= print_interval) { - std::cout << format(counter) << " per sec" << std::endl; + std::cout << fn_name << ": " << format(counter) << " per sec" << std::endl; counter = 0; lastPrintTime = the_clock::now(); } } } + +inline void bench(const std::string& fn_name, const std::function& fn) +{ + + using namespace std::chrono; + auto start = steady_clock::now(); + fn(); + auto delta = steady_clock::now() - start; + + std::cout << fn_name << ": " << duration_cast(delta).count() << " ms" << std::endl; +} } \ No newline at end of file