From 8ec03bedbbc732a01beff959d474cf2f3d664589 Mon Sep 17 00:00:00 2001 From: kowalej Date: Sun, 16 Dec 2018 21:10:29 -0500 Subject: [PATCH 1/3] Add logging utility which prints messages to standard output synchronously. --- logger.h | 19 +++++++++++++++++++ recording.cpp | 50 ++++++++++++++++++++++---------------------------- recording.h | 1 + 3 files changed, 42 insertions(+), 28 deletions(-) create mode 100644 logger.h diff --git a/logger.h b/logger.h new file mode 100644 index 0000000..cc80461 --- /dev/null +++ b/logger.h @@ -0,0 +1,19 @@ +#include +#include + +namespace Logger { + static std::mutex print_lock; + + inline void log_info(const std::string &msg, const bool std_out = true) { + std::lock_guard lock(print_lock); + std::cout << msg << std::endl; + } + inline void log_warning(const std::string &msg, const bool std_out = true) { + std::lock_guard lock(print_lock); + std::cout << msg << std::endl; + } + inline void log_error(const std::string &msg, const bool std_out = true) { + std::lock_guard lock(print_lock); + std::cerr << msg << std::endl; + } +}; // namespace Logger \ No newline at end of file diff --git a/recording.cpp b/recording.cpp index b8765ca..506d346 100644 --- a/recording.cpp +++ b/recording.cpp @@ -51,7 +51,7 @@ inline void timed_join_or_detach( thread_p &thread, std::chrono::milliseconds duration = max_join_wait) { if (!timed_join(thread, duration)) { thread->detach(); - std::cerr << "Thread didn't join in time!" << std::endl; + Logger::log_error("Thread didn't join in time!"); } } @@ -75,7 +75,7 @@ inline void timed_join_or_detach( std::this_thread::sleep_for(std::chrono::milliseconds(500)); } if (!threads.empty()) { - std::cout << threads.size() << " stream threads still running!" << std::endl; + Logger::log_warning(threads.size() + " stream threads still running!"); for (auto &t : threads) t->detach(); threads.clear(); } @@ -107,12 +107,12 @@ recording::~recording() { // stop the threads timed_join_or_detach(stream_threads_, max_join_wait); if (!timed_join(boundary_thread_, max_join_wait + boundary_interval)) { - std::cout << "boundary_thread didn't finish in time!" << std::endl; + Logger::log_warning("boundary_thread didn't finish in time!"); boundary_thread_->detach(); } - std::cout << "Closing the file." << std::endl; + Logger::log_info("Closing the file."); } catch (std::exception &e) { - std::cout << "Error while closing the recording: " << e.what() << std::endl; + Logger::log_error("Error while closing the recording: " + std::string(e.what())); } } @@ -121,7 +121,7 @@ void recording::record_from_query_results(const std::string &query) { std::set known_uids; // set of previously seen stream uid's std::set known_source_ids; // set of previously seen source id's std::list threads; // our spawned threads - std::cout << "Watching for a stream with properties " << query << std::endl; + Logger::log_info("Watching for a stream with properties " + query); while (!shutdown_) { // periodically re-resolve the query std::vector results = lsl::resolve_stream(query, 0, resolve_interval); @@ -132,8 +132,7 @@ void recording::record_from_query_results(const std::string &query) { // and doesn't have a previously seen source id... if (!(!result.source_id().empty() && (!known_source_ids.count(result.source_id())))) { - std::cout << "Found a new stream named " << result.name() - << ", adding it to the recording." << std::endl; + Logger::log_info("Found a new stream named " + result.name() + ", adding it to the recording."); // start a new recording thread threads.emplace_back(new std::thread( &recording::record_from_streaminfo, this, result, false)); @@ -147,7 +146,7 @@ void recording::record_from_query_results(const std::string &query) { // wait for all our threads to join timed_join_or_detach(threads, max_join_wait); } catch (std::exception &e) { - std::cout << "Error in the record_from_query_results thread: " << e.what() << std::endl; + Logger::log_error("Error in the record_from_query_results thread: " + std::string(e.what())); } } @@ -172,18 +171,16 @@ void recording::record_from_streaminfo(const lsl::stream_info &src, bool phase_l try { in->open_stream(max_open_wait); - std::cout << "Opened the stream " << src.name() << "." << std::endl; + Logger::log_info("Opened the stream " + src.name() + "."); } catch (lsl::timeout_error &) { - std::cout - << "Subscribing to the stream " << src.name() - << " is taking relatively long; collection from this stream will be delayed." - << std::endl; + Logger::log_warning("Subscribing to the stream " + src.name() + + " is taking relatively long; collection from this stream will be delayed."); } // retrieve the stream header & get its XML version info = in->info(); file_.write_stream_header(streamid, info.as_xml()); - std::cout << "Received header for stream " << src.name() << "." << std::endl; + Logger::log_info("Received header for stream " + src.name() + "."); leave_headers_phase(phase_locked); } catch (std::exception &) { @@ -200,7 +197,7 @@ void recording::record_from_streaminfo(const lsl::stream_info &src, bool phase_l // "forgot to turn on" before the recording started; in that case the file would have to // be post-processed to be in properly sorted (seekable) format enter_streaming_phase(phase_locked); - std::cout << "Started data collection for stream " << src.name() << "." << std::endl; + Logger::log_info("Started data collection for stream " + src.name() + "."); // now write the actual sample chunks... switch (src.channel_format()) { @@ -263,14 +260,14 @@ void recording::record_from_streaminfo(const lsl::stream_info &src, bool phase_l } file_.write_stream_footer(streamid, footer.str()); - std::cout << "Wrote footer for stream " << src.name() << "." << std::endl; + Logger::log_info("Wrote footer for stream " + src.name() + "."); leave_footers_phase(phase_locked); } catch (std::exception &) { leave_footers_phase(phase_locked); throw; } } catch (std::exception &e) { - std::cout << "Error in the record_from_streaminfo thread: " << e.what() << std::endl; + Logger::log_error("Error in the record_from_streaminfo thread: " + std::string(e.what())); } } @@ -285,7 +282,7 @@ void recording::record_boundaries() { } } } catch (std::exception &e) { - std::cout << "Error in the record_boundaries thread: " << e.what() << std::endl; + Logger::log_error("Error in the record_boundaries thread: " + std::string(e.what())); } } @@ -301,8 +298,7 @@ void recording::record_offsets( offset = in->time_correction(2); now = lsl::local_clock(); } catch (lsl::timeout_error &) { - std::cerr << "Timeout in time correction query for stream " << streamid - << std::endl; + Logger::log_warning("Timeout in time correction query for stream: " + streamid); } file_.write_stream_offset(streamid, now, offset); // also append to the offset lists @@ -310,9 +306,9 @@ void recording::record_offsets( offset_lists_[streamid].emplace_back(now - offset, offset); } } catch (std::exception &e) { - std::cout << "Error in the record_offsets thread: " << e.what() << std::endl; + Logger::log_error("Error in the record_offsets thread: " + std::string(e.what())); } - std::cout << "Offsets thread is finished" << std::endl; + Logger::log_info("Offsets thread is finished."); } void recording::enter_headers_phase(bool phase_locked) { @@ -373,16 +369,14 @@ void recording::typed_transfer_loop(streamid_t streamid, double srate, const inl std::vector timestamps; // Pull the first sample - first_timestamp = 0.0; - while(first_timestamp == 0.0) - first_timestamp = last_timestamp = in->pull_sample(chunk, 4.0); + first_timestamp = last_timestamp = in->pull_sample(chunk); timestamps.push_back(first_timestamp); file_.write_data_chunk(streamid, timestamps, chunk, in->get_channel_count()); auto next_pull = Clock::now(); while (!shutdown_) { // get a chunk from the stream - in->pull_chunk_multiplexed(chunk, ×tamps, 4.0); + in->pull_chunk_multiplexed(chunk, ×tamps); // for each sample... for (double &ts : timestamps) { // if the time stamp can be deduced from the previous one... @@ -400,7 +394,7 @@ void recording::typed_transfer_loop(streamid_t streamid, double srate, const inl std::this_thread::sleep_until(next_pull); } } catch (std::exception &e) { - std::cerr << "Error in transfer thread: " << e.what() << std::endl; + Logger::log_error("Error in transfer thread: " + std::string(e.what())); offset_shutdown = true; timed_join_or_detach(offset_thread); throw; diff --git a/recording.h b/recording.h index a31ffc1..304ab8b 100644 --- a/recording.h +++ b/recording.h @@ -2,6 +2,7 @@ #define RECORDING_H #include "xdfwriter.h" +#include "logger.h" #include #include #include From da7673a6e6336e201279a1f8f21bb08cbe33381d Mon Sep 17 00:00:00 2001 From: kowalej Date: Sun, 16 Dec 2018 21:22:08 -0500 Subject: [PATCH 2/3] Revert back timeout fixes. --- recording.cpp | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/recording.cpp b/recording.cpp index 506d346..220d415 100644 --- a/recording.cpp +++ b/recording.cpp @@ -369,14 +369,16 @@ void recording::typed_transfer_loop(streamid_t streamid, double srate, const inl std::vector timestamps; // Pull the first sample - first_timestamp = last_timestamp = in->pull_sample(chunk); + first_timestamp = 0.0; + while(first_timestamp == 0.0) + first_timestamp = last_timestamp = in->pull_sample(chunk, 4.0); timestamps.push_back(first_timestamp); file_.write_data_chunk(streamid, timestamps, chunk, in->get_channel_count()); auto next_pull = Clock::now(); while (!shutdown_) { // get a chunk from the stream - in->pull_chunk_multiplexed(chunk, ×tamps); + in->pull_chunk_multiplexed(chunk, ×tamps, 4.0); // for each sample... for (double &ts : timestamps) { // if the time stamp can be deduced from the previous one... From 17ef4136ee2b511c5d427eabecbf446c7daee91e Mon Sep 17 00:00:00 2001 From: kowalej Date: Mon, 17 Dec 2018 21:59:48 -0500 Subject: [PATCH 3/3] Clean up logging. --- .vs/ProjectSettings.json | 3 +++ .vs/slnx.sqlite | Bin 0 -> 77824 bytes logger.h | 6 +++--- recording.cpp | 3 ++- recording.h | 1 - 5 files changed, 8 insertions(+), 5 deletions(-) create mode 100644 .vs/ProjectSettings.json create mode 100644 .vs/slnx.sqlite diff --git a/.vs/ProjectSettings.json b/.vs/ProjectSettings.json new file mode 100644 index 0000000..2b7b33d --- /dev/null +++ b/.vs/ProjectSettings.json @@ -0,0 +1,3 @@ +{ + "CurrentProjectSetting": "x64-Debug (default)" +} \ No newline at end of file diff --git a/.vs/slnx.sqlite b/.vs/slnx.sqlite new file mode 100644 index 0000000000000000000000000000000000000000..f6d7ce411a3a1564eb8af5fa34a7676f474b2850 GIT binary patch literal 77824 zcmeI5dyrdKdB7!0EA317u58D$y>TqRuoe5t_x(sFL)ThuEVAC+tahCQvt91v+_i{S z+DKZ*OM$WuNy=lGmOlP~7CNOJ=uqebh7|s2m^LltF=dOh5IG_6Qzek1QcnJxM>FZ%15AALLakw;tJRHFqgkIscCAtC)S8WD_iJNi zs#Zr8Yq`=-i7L&PCl<>2%FJZ>!ThBirLmM5&gW-mwrVfsPhARUx>VTQGn&qoz{pa6 zBWLtg)Zetsi_}YYEsclUk0#!F?c)x1)(P%9YQ*U8V9r^@r?nNqo$zvL^H8=YEbW9d{^05J=0V%RLGtjY3p z8Ojf(FHKCA{ft~VGZ!c3OXnx%Pw|pe=o%AY=0}-Yuh%#3U)Sq3yN0ZO34~eu@$Q5A z@3HVpvOaV$0UMgz4^Td+VY@)HE_ru|46Agyk{bmyl3OfD{nvGY5 z{cL_kTqNWM*X<#GBMlbHckGbE`ifn5^#wa@%?lfA(AD|fjh}_z#1?9+sNK<5*Ov0w z#TP0UpgV+42m9XX!F29yA%1Pd@jX9VoZd3N_yX6kA+K5&XDatEb{`$SPB&85x%?2X zSn!bWC9c7d{-PUt5w+UTu(ovG*W&4Pu26_Sc8}wQeqwI&;k&`G2ZjR!{^th-tLQrX z&X4Yvr`MgbFWQ^>F}r2mNn~7OYAT&8Gk%RZ?I+OHEzjvK)aWeZ?l~Hk?pu9PtzZh> znv5#p2Y$cj>lt`5IR-={U`O8EGZ1_uh^ja?yKe;1pp<91_p%ZV4#d1}iwlo!B%QA9 z$rHVziUz$z7wh++^;`HhPwH)}pw~qN-Z?65Z0S<|TxIL~$h6+> z%o=Ufx`N;t-s?TQ*A{rWn3`CeUdWs4EywLTeplo5JyWyu<;uM?&YKUk{%u{O*UtuD za-sycc{shq=QuQ`W+I*A#^alZ-B(o9>C_r40dK0hl4RKZJZV6$>vdkxcFm(Ow=0!9 zeLDV-<7(|k;GG98x6vc(r~z+5;oC&W(ISDT8qmJaK+MAC`FJ`vJ|4fe;-u*r;QiSZ zO5>7mUGMShNp7BNUexRB;A_3k&Ux`%gkjCtNCvLS!8>F0cj%|-55X7mAp{5kLVyq; z1PB2_piAK0Z%huv?*6R`em$-9W;d(uv`L%wJ`DaFx%9$x&eBvxWDHSM84hk3!;&0z zOA`zkiGsFTGx?oxik|hqYnxx1G#D>6|vZ^ppc#{!L* zmS{1OA@Qt+<13cLh=^kuRZ@9|(?wGS0IG!~M%Hwl)i{MQ6vOZkD2VrLGF1Zs4_Q|g zMbd1>Rzw+6QlWwrRb@0;GQdh%;8~tg6o3SE#HhN)dUdDkB2G!yBo$YN$tXIqcuUft z?x1c(4l2mdHK;|KQ&djlkO1~7h5)s035+VpJXEk^F<`F9C?aq3i0364YD2L#Qximi zu|yT(BTzDIq%yXwvI-|!rX?UoWhFt80I?-=B4lSvkdh`aV2)rTSwK4QP;E^SCB547JH48EVvGWTbd?rwg*?8EyzV$07#)$f63>jtp=WQ3RV+3+m41I9W3#OOZK& zF(g0MG_d^mQ>lW z4VzUI#xhh^0Azpwd!_{*ZKygJrpT(Un=;2k0+t1Z(+#K*1O*d05E(3#0~)n0Ni6h( z5(i2M=>mdk=^1W7GY%VWo6t5n4JrdN5e?CVK2ww!PL?d*Fm2hEIR>$;A@i7cHzmyg ze+Z?7SOuA)0NtUXK!+g;3bbV?hox(x$srj*B|$|3Z;{2_Fm^f-nuI1plTu~Tl6aBT zdGH%#sT}lm3L~%*q$HahquB^riz;Iu5Lf|9fh=gS03&DclK5AN)%^Q{g&k2J;wx%KjdL6^oa3==O1_L@jXu&MYv#hDk8p3`YM5DO8vp}E^OWGAuETY*hB1CKwjDP*_}y^920Td(d6 zRTV-h?MozMXKClL3zL|5^`_KZZ*;hmyOJ?RD7BE@LDp<*am~VCIQ}fBoaI?g&GXz{ zl5&?M?TaU4Cv#O;+gR1T=})dG6eT?VAD}-Fqklkuo&GreS@=pmga9Ex2oM5<03kpK z5CVh%AwUQa0)zk|aB~Ul9!M18y)7A&dPg7FodB7?mC4>u42uxl)FawxP30I&ZaANiXY{Z0C>=s%!; zg?Yu2mso$pFL|vp_O`W9Z%ztIRocYtt2QqKXn3<`}>CDLJbE8j< zzIXH&M~%_DMt6_=2P8y3ga9Ex2oM5<03kpK5CVh%A#k$@j2}ub~;8(0)dq01Vdi+=_ra)j_H(JPSw&2VgrrlY$Hi~PFm9EySj;3OFN3>e&jRyQL z?XcdFt$G%+_4Rruq&J>-O){H}PODjOhXM~APQ{MJhEi88`_UHs$Lv<|vTyD99jVyK zP>{K{<_8`*l!^%u2qo++L*!*Ic0lFq?Wx$TuTn#%Bx%cf!&-*_|J|vhWz?{0dZQSK zaL0Hm#^4C%TCD-5*t&^=;Rg=7wz}*vj-IUtTw8lVfpo|ByMgl_^XZz=i+L!Qik*f` zgMop#xqYeFVH{kZn7mMi%Jcz@-{vN|s@EEi!vCaiK3ZI_`GE)b0&<8I2<)1A`<_&+ z5Dp9Ew{LeUcE}42mVIB=mDigqE5S;-Z7dZV2mR?vsXS9H`vx4RQ!x#Tb;B>%@-$k} z&5fdIulQO=;b<)>qIIq^SqrY8fnm>qD9C|+s%DIG|9j&XSDdOx>}sGc|G$XWF}mOb=j*KONvqg6!XuI31FJRxXn`9Pdtd?89*a z(-`Zu+i+rh=b=MGF0M7yf*IC zpFT+8)L_nF05cCv6eO`Fz1e{T&MY(~;H>`_gYy9H_+O3D-=)7se}Voq{m1kN>37p_ z%zThup?{t}Ppg^7Gb@?<=wtK{^`F!?s4r2^P=7?dpL!?k3s|8Rs0oUt4rbKM4>HeX zKAZXEE!X~tL4*JyKnM^5ga9Ex2oM5<03kpKyi5YSlPBV#asBY|@uU(Djo*8FD~=sX z-W?7LjO~YyZV3&H?uU;!Sp~=U!}+n~u~=Y4fBEq4GWxi_r8e9+0cCxDy}IHK@Ce{b@1Y|BWWN*)HGzq4VV6D=^1hp~P( zc_J1Z+h5+hCs_zd@Mu4iJmkup;l6X%9q*4O$79_A|9Db^oBkvI14$_y)*bRYwg+N4 zV}3e$Bo-X>JG8cp`UjJHV$QJNDO-5l@027m@OQF`j{Kbhb%*{=l6dUz)I@Ob@0b)A z{X2PvhyPh{lcCV~AMgK9QJ;*_pQGPHU!sr07@v&cUuNGxq7wpy03kpK5CVh%AwUQa z0)zk|KnT221f*0lws>+UzqG+gMYagPqQWahNsmL8_k^srjb&vn?`u{kU#Q*>QpJD9(6#cu-8GsMd z57K3trw=>l0DhbLd+IaPN2&KxPf{I9r)H?TsZ-QGh(> z&NalMK~Hq;Z`ZPLnjsb)Pb8ev=boRN%)$wVShUX*{m)53_KVAQojk(dUG3XW;}vEE*Yb(|YFf`?GLtAQp{! zT7Ul9zs|x@fmk%;i9Vyf4xbW;MQKm;sW0!(!YP4Rl=7(lUgc9`a5`XoD4z0^o_N=> zESw66m3HlNGkpB}RT|C$90Da*u=x*<;`RS=`t>pT$Mg^B@6-QI|0~^sUjX3-Sr*ZLSW}$#xtP6T;1$CD4GZ!c3OXnx%Pw|peaH@El2&HDDgRWjrjD?Lg)blOu zJ(=Oc=Fv<#_W%>$yijXc=xTLi)o9iykzH%lI<;nF+5OsB!IUc2a;2XVcepVf z#&pxvadVq*KDxc#zEY`KUteu()x)j%$Z$GWg@!WgG!(~pQ*Sg-tE8Kk(Q>pj6)UPT z5^gZj;65pI8%|Vr8&r=i4mr){iKX7NHDF^jmEmx+i3SInO*AOz_&aDe{*%;6#(CIp zeIUOa7YRMbuKN*p(^_-nDG_O63$<0$?&zy)OL_c^UZ`Av2buRIIX#%poh`(#jX1vN z8;sLi#us1UQXTTDb#bP0|6&>1p!4YPb-Izd&gF-AuMzN&@FlLnk^Z6^dJ(nS(6F|2 z-q+&kbgoc{KX#Afg??gg^5MI|um^?%1ODd+yhOkAqr2tlb*C)62E1@@>c{MsbtjQ= zZ=t5rxiaI|Sk&>C=X7}0?JVQ&IU1JkTYXWjU<%!uj4I&=e!u7I8F*K942VVmzVJpc z5PTzusyH^gZv@exlxMl;anayF%Drz=(d*g*JxMgLfv{smg9EM=4SI<# z*6%_4V!pLq74#mPco^b6fh%on=~Dh&B``$s!lw0hXVz$=))fTL@LuoX`}SmcYGQGE zA#bj?9JlNEU5%Ic)a-n@a_@{Y7=qTnon3)3OmNr}CAiJQ=_L+CpfNQQ=^Qs6-#qNT zqM}Zx)>sL6Q`MCu!|vxv1A1Mr^MbZ(9)-DGsod$)@rN8&Yd-?-JZQO%9$Cku)5vWi zRMe_-@uF}j)gT;}o7|Aw#RLkJK8ga9Ex2oM5<03kpK5CVk2EkIy$U|n@ zaw94DL3Yu$B%Kiv;uuj>HAb^6i{UIwlxmCXunevPmU} zaWaQCHCX&i@rYAJg*O>VP)tTtAw@&Nw<^y|rpWP&tk|Fq^Aub<{zADcqu+*W2Y*tJwl+r?u{t*GUg@uxl%L zUIiz0RTde?>ij7S+4_3DQ}9yXFN0X+S>*fDWlJjRqf_WF?hVMfJ5_rVr@tk`A*0^=NVsFtOfg-iu&iK<}XbN>!M@02IwesMLTW z8UQuDNyU4vH+T!U9v=Uv20j#{-$4E4$k&E04}KbM$cGRh1PB2_;8r2<#8@_c8^a8~ z^MNZh^eEmHfOpF{i*Pm6j^2AS&=)J^2lCOdyxz_XKTugX58Hi8i}TgW#qw62iK@5# z3U4&3!uF=pLO!}MP_gn8)%-cV?d|w-R|G58nf!K34p_hBE?T%My(sv_AQarWoS&MX zy|5+M-r_JUh|bRRZe1&T_t^5eVjuIuDpS?s^_#mT3CH|5y(xe4btm)iXRg>SCX^#s z>dxg}T(^9Ys>IrJJ)O$T3~X45=`CBwykvp4tgH;;q`Zxe5LBFq;H-cOXnUc#5eWc77k|( z5x=MR*?!@yt@rR?tv%s2rf}ePNp#np!s>YWsVDIfFP*vMEK?WWwnjV4=x-m7taxHO zdhzgGHoSlo4(z+uiDSLQ<)mKfU6XqYmi~(4&08OI-r`}`r@vAkELC>_HfWBo=vohp zmA(LC239z?-KBZ`n+R}Q-?EtIlZx!FaGT~OZvn2mwb3u-4cyBJZJX@P-L}@r-dtyM zHGW2J%P6#0nC#6BZ-#WY%yb_G(T%7-J9~5S`F{iSoiX|=^hfBo(u?qwd lock(print_lock); std::cout << msg << std::endl; } - inline void log_warning(const std::string &msg, const bool std_out = true) { + inline void log_warning(const std::string &msg) { std::lock_guard lock(print_lock); std::cout << msg << std::endl; } - inline void log_error(const std::string &msg, const bool std_out = true) { + inline void log_error(const std::string &msg) { std::lock_guard lock(print_lock); std::cerr << msg << std::endl; } diff --git a/recording.cpp b/recording.cpp index 220d415..78a8399 100644 --- a/recording.cpp +++ b/recording.cpp @@ -1,4 +1,5 @@ #include "recording.h" +#include "logger.h" //#include "conversions.h" #include @@ -75,7 +76,7 @@ inline void timed_join_or_detach( std::this_thread::sleep_for(std::chrono::milliseconds(500)); } if (!threads.empty()) { - Logger::log_warning(threads.size() + " stream threads still running!"); + Logger::log_warning(std::to_string(threads.size()) + " stream threads still running!"); for (auto &t : threads) t->detach(); threads.clear(); } diff --git a/recording.h b/recording.h index 304ab8b..a31ffc1 100644 --- a/recording.h +++ b/recording.h @@ -2,7 +2,6 @@ #define RECORDING_H #include "xdfwriter.h" -#include "logger.h" #include #include #include