# HG changeset patch # User cin # Date 2014-04-14 14:25:26 # Node ID 2880242f987a0dffb724d7dfe9330673f13464ec # Parent dabf79fde388d19cd5b762a3dc4a37541f226344 initial log capabilities diff --git a/Implab.v11.suo b/Implab.v11.suo index c371d5afdf7e3cfb5ab2092a2baa4b698305b78e..abba552222ef3eaa7ffdb49cf74135550b033615 GIT binary patch literal 90112 zc%1D$33waTnNQB0I1M?t!sXJG4b)O3TbAq`C9-TK1}AZB$Du(a8Oviw@mLZ%;sla% zv>YW3w4`KN+R~K3LYKCXF3V9$p-@`da<*RzeA`m!c1yQq+0cX1Qj-1u_hzKgXht(5 z$(Ci$^Y=W5-n{>v|NF1^zZYMa`}$W8FMNY2!pF%Za_smFGFA4j3gRT`;RHe!iOy%f%Xci0Zq5YK|R0OB-=I416acnIRD;&(IQIs@XF zBJ2%tJrUx`gy9&qaTLsqu? z#rtoG*YCphKOjB`@gay0Lwp3{w;?_X@jDP7lYRe$c>kn${XSfu7Vm#3UVkKBeQ;0tkpQZ3JJih|*RmFP@ufe-tiSKdY{k3@i8LvZ~lL<#@n?`MfuIsV7z zQ^oveiuFHJd@slUQy|_+a&e@E{|gJn;Q#C4`WZ4d)&dLvtA}FozZE8SXr}AG04og# zt4AqxO)7yM@wfp!Z3eA`08)%8YCxe2Mssy$qi1Z|348n zo{Ykm(?9C~UXr$RL>%>9w9ZLNe}w^l{;;Tk`mcldW03%5^KX#WG7i@abYtOks6RHP z8TiO!FD4RvtN$l*|93&Vhs0jk0rl;pxUUob52)f>WkCMNLo#w3Bk+y3Kk|b02H+zf zQDXu=((Bh4gzq*0-)#RQza#ap9()(&aJ0iY1;EEKy~iN@ddflNhcEF@M&Tp>@hyY! z-IUAA3*Yqo`!vJ{48yN0Iee5qf6+)ngTX9(c_=~ulS=OYQiNjKzufTk+P{uURI~%m zf0VT>CC2;zS%@ja@bj+#2p>~4nt=a2L}^{qhwssak8ph^;J*m*U4!uJ4d5S~q34=_ z|8Ec_E=C`|R~J6Y(^^cx|2Z*U|2hNs$L#q3CB(f3;n&lVl^4G0_4jqcWLZYwyA7=W zlFZU5{G)`)!Y~}L`C;w`f&YwB`ZGwmZ-MfkeGrisjZ!XjkoYKt$U&Me%CV=?ba{|$ zf%5L8rH)e`8u|GkQ1L^+?P6ZNDo>2+9HP1NloLr%em?})$2xx-e*cmg-=13Y_S}a) z^VnO2rQ*Jl_7@>t24~`tASozo!j0CHE1Mi!~4f z?1r*LV1Cq)8^;X(V>P(xz^y<0+BK8z+IXPf|EF19Ur?(-z}c{8ciT`*;Ch2Q@*$0k zATg*_Jf;4#i)^D=C80DaiVO3HLgXKaRVDpr09v&bMw1)<`(b?9Ve~oS8h|_GeOusp zOIk{lD;-%{0DRP@?rt>$zZ;&{!0#M1t-Acz415fe#j8I5pFbe}L*1*Sb2S1RYaq>k z3WyE8d6QrB^j4qv^Ouj@`QO*J@{~eW4m~>9Bpo>pp`~UPEnE!y)9_|5Su*v)hpX2g zIC|vmCtttsZdG{M&{E<(u5>Z@YawgR!0(|WKSi5%2UW8ti6lI;NgabX@7TI_C6fG* z!ygp{K9mecBMHYUKElVtAxBG?zTo1!w$@#Iv6!$c84pJWYHNlPp=ewP_tw_*@bLsB zTj6#%@vpYVpAwR(IKLvor;>3_sIBQp^$Ow8h5WAW=pY|i(d+ec4WR~)tEt}2I~$uW zsl8aG6sx(!wj|dp@TGxO0{Y)((f{V)zfMX||C@m?r~fllG1GblL_Jg&EE-5f;yR}T zzbN|?CHys%dW}*$B)LvZYaOZ;+aK*vjKW9Tj&2S3%_7$@2xucp;o}-8FG+TA7f^rX z)ui>WRk18%`wNts&(@6iDV>oNkyfTPmWuV4Y%7hxHz$9$=>L2H$A2Z$|N8WYKL3Mo zF_lsHJ4iC4bIdPN)=5Q!e1roL1S4Z(GH6NKH98JDiQoH zk@_|Uy?Fd9(HfUv1*VB~#B_gjD8|M4_;jQ;y26+7P`~Ln=Oc>5YwM*cP6#J=Nf~T) zjVOh52}Pqbs>I4n#+$KNOf1|i_0I4?cMqgRPXG8|>+k>4Za=vBQ_pO_*CC*_q8d$% z8u}1jFE*JI8gbN&MW9OzS68Ohkng zqQc-7erJ-8M>ru73_}*_iete$L{mIgl&?Nwo9{aM;<-1!bL-u9zImzYC~7Wb{AO4A z-9P{K(&yid-S^8wuUvK3{yqPv3P(%+6ErV0&&-}SO7tXU(tvDi{J^H4eBt&-yFd8! za~~gkZ^=2eswFE<{?k(!{>^U3)fAh@WEfyx{QJGDZvW8I@2&kH{`ZCcFRPYZdbwBS zN44--NQYDEMu;~-{2av3t;q&C2Dis?cItkBMe@jr){lRrdd<3F3rZJ`4^3{x;dOQ9do{ut-w z31npW-~8J5!tB2;CmH^)Thvho($<$5Ysa4SuAr#M8D&TgDIouU4q4pW-4s+z;w@^+ZMJ?O0zvYrHBnJ|7fn+04 ztu)R8#y`%f_b2JYmn8rB?2sJ*A1PS0r!S=bN=lB6{(g#sQj}TJwmrsBTR{8cx^~Aj zcE1j=?si~okSI~kydE9dGY05?8|EkN(=!4e(@HEeepAZzf1$y=)B^7Nv)2F74eI+( zI_X-Z+zlkjrsa0w%L^F)xR>)KaR4&BFA?NyrXkPS0At?|n8HV|+F@}4@X_{jP=v3) z{+HhV_i>0<5To#Q?O$zZ%a2lGqwv26aX`FR>OVG8*delwD0e!khnfQFk9%SlXuwz3 zzi0=PzoI@LwPZ%&e}a(oE^{S(Y;&Z0V|iD-Ou+WX{m;`(z{h>TlKw|q{}!d|j~)#! z$=|1&fRB5c*BTuEE(7Ba_lryZL5#ph+#yNzFM^d{Q0(|yXSnql{fYb37np#L)U(w7 z`t{e>f1w|wWhUU?OV}O&3_Sp^10Z!m&vyW}^8e((6?{|yW zPZGBNP&!!Kbafq-ip50>GU+{&FCD(!`QDOehn)}I`DkFqGbf>UpB!?`-sp9E>~3F+ z)86E9x$TV&4FR{`-RzaiFXumT$BhTC=4x)Z=Q;aZ!YiLPE5C#+#7it59SSFSM<}s- z_vJp1-|Ke!8tu+jx6kel_&xTzxg5kJr7&Mq2K-wJdeQ-{paZ24}z( zXf#x4b^%BLbNlYl($Ormax$MnY=FvLRhc)7s@Rmn=_-58Q9OsV*Nt?%FQsBc3;&M~ z{BOqoWhF6F|FN(CM|^H(|GTCCm%|@@{_m^A;{V19|A*g{QvP!bVZQ#1zY6}(&myqLdMU@u&9!(Rp=pB0RDDEdM7oVzUT$XlS^S?QH}?M1n>ntkULu8JLrE5 z(MSgu8srA}j6IGE&2enVp1k)?$6o^1y?DWa1=nn8zwnAFk}Wq9Ca3J%_xxr4V9SHO z?X_>-w&Pu!40v_z-$IXbPpm#Pyl>#CA8;??Zy1&NVLtCoeRJwn+y3Cc`IE<=o^;># z@8nB6{@+03PP+2YSL$D|$vYBi;YSK6BTdOzc=(}=8`3GU{rVvV z)?q6Bq7_Eq25J+`IND_};=FX+Nq2Q{S4T%AlgBg9b}>-}AESI%c0lS1ae6PEO>&=# zh@p{3j#9b5)~-aXa~~~Zz8ohj!HQv3b9)=sq>b)aVZHX&G{i>11Yc*`_r3&51JD zdInsWepb4k>Lpd%%#z!(o#{E8e;*Cgu*oe8gOoPJ5g9CKb#UbLhmTT|aXN}q6dTA( zx=^D{TWIZLX}NT6%bud~rM794)E{bJt$}*3r|p``YIB@{*&CSf?E=+aT}|gyU(UEW zA*W9>)Shw{sg15UeYcDHN#f|Nl3K8(wY?3$-AXdNy;LUbu^QRVf*PQjcLFZ+kaHm& z`ugdo<&^x6)+l;TnqOIcb8w zX1W`o1!|8w0h*vD0r-#m1Ojxn+M!Q;@Eh)>55QYY>4U!pNZCxkY7*tZ6J>4RZ@P}T zC9k2DnhEGJ%)N$EkSTzTBcX=+EMTSd)44fB$A_2pEn-`>R#R`YOnr09;K(Y2yaWzP zJ99LjB&Ad(@4gOdYl&|q%$M8B7JXD{m_hy?gPbm~M!fM6k2VXV2UU$a887%3=}Pq! zN-BMPV3R`l5TzjclP5Diq@!$Dhnb(KdsCD1A1~h!8%O*HO0M+z57r9B@g9}KS)fGC zM=_Y(^S7M4kf%mTs5T!WPdQsP-_mg^y%mZ{m<5gz%1fxw8fN>EaiqO3CJfbjYsJ*M z5Ds*pVrr*8YTIewUTSgM7Pp<#-`gstj%t*@pZa3NwLLbjbt4kZVWf`z6IlZ%TK}ics=%7D-cx##Z0T=g%gRv}gQbT-0;urB#zFR4O(uPMR{2u-2J5 zEn_B^@ib)J^G0ERzSWU-`B+W15o;!;!u?-9US*muceY4=RVg&0fPZ z`yBM^xUtN*+6X@{*C(pWo1M`9trU-XAax_L!?h9qTvXm%PjNBIpz9z_E0s3~pwlnfYd%n;g`vq$1epqadk(PBDKmL-vJn_I9dbrq@PBrJMltWcdC~7wM%>9y?yj2e8FCG%k9YP{}*wJ5&yrq2Lts@m3@Ku z&aD4m^z;1*lJUulzE{oo|3zy$E&sph6*ETII##Iv-zy1`%?g~+>>$zcdM$A`ktoKp6#un37#%)9xrSyvuw4QY5 zf*I2x)+-F})e8qg^G9}sp1pAq<8oxJe;Iiz1#n1KHb#FRn!bq4*fn`!?alg#;pT4RRIKUdCp zQA;n4aO4SYEZb_JzUm<#VIE_v@pI}tF7id!m#xl9?2nw2xfL(JH%i8znc*wdsfK)5 z7`erkf~Z7gUnBonh%7_je*oig%~72C{#hC4YlbJuNM8iPPVLOB&d9l&<)O^^7-bx~ z8L3OqkXK(OB{0*v#^@Ckab8qlu6n-hn54rDX3=VIEglmkBxblLhfJE4U&e*f!(K7x zO85W1xWGAY$uHTH<^O$R`+qM5-=n^>fVF0C0n~`O-45*R9YQRvb|G5rnKnkl+Hh)| zuAI3w(AMlL)L!TPxmwtUY&Q3;$Z@KV*V+ z{=?YjKdkc~tn(krjY+KYA11O7pYi66(c-o(Zd--1n{0GbbljZ+uqFc(2PybJ&@Be4KNgS;6AJi>{tn(kN^B+pB8?erQ z7`u3JJV~gm^B=79A1vL`_|>Oa=RZi}JF8K{X#z>U;RuN`?Do}8lKp2lc&Gd$l%8Xr zd6A)Sb$iS4F|Q#+}c*c0eIZ-ux=bQ$%gQp*0vaW<@gyH4B_%%C1WzD(qq z)yl?0?OEFC)O$xM%eIVqI4o^#J86IL;)QkF-pM@C=&UpcGXNT2^R7Ni7~etwO0eu*{=>--Y!wz1AH$$x&yNSqX6oyB3c zgw|Och5Dqe#Irc8vly(i7_74x^!D;wXEBVWvl#B0$M}}x$B4Klw^JBN%3)(mOE@x0 znAI!tFT3E^e)wbO-tcKWD_O%Xpu81>y@ApI%JTN*e1o&UmC{<6cNa~~(=~z6d86;& zZz7&0Aq69L#geD>wA+~X-s#Y*y_vHpO0n*b4PW%4drzVlsJwV4Q69h`i30F|f>ZYG zd;T(iu;szt_S!dZ+wrbkxS(_=Y7-k&nIGn(bonEuH71Kf8Gw&kDupTj^h5dq!mO5N zlYI94%XHfN{Yi{7uOf$SElZv7cX^ru746`hx3*;~qPVkV|?%kLBJbtg+?Q66_Vv@0~(yirqJ;N5ivx zS}Jc&saMV+tKf&L81qw26uXWx`oco-KT&2WhGO0ktgh;4Hk7jJ$n~ zQA_vXP@ ziCX!zcOCMyN7KRd`7i1HhwSJb)7Jm^Q%1W#8d4V)B>Qott__13`+u4Nwy~5^H4YGd zO*j;fCZhdGM^8AB;)JebsxKUMbn}Vi#&D!BIxIVe&gH;^=$y4R{*;hR#rYKxK9!7f zLTyb)s#geyF64K0M+f=Hie6`Ze?z~w-{tCSaB}rrH5MwS3(Co13?y2(B!}~1(ek!LAT03WdtWFS-obx-aLblvE;I-) z0%2b0J9{~NiCOykp$5&Vu+XPWa@O*0ENWK3n2lq7J^xBiRJmI7b>Kc=p!nzu)!kf4QT+ z>+k-rba;+VQ_E%0eEp3oFc07Ed~eCK!_J59d^9lQnUfApR)a5S%>SJllX5-W0)py} zMumik55-`_iTV`OM7VWTX!GnUGVPg zn&_eLyj1tt=Gm&PCJ)`Ia4h#^+Tu{+iaaP$*7P#aj;>S`5e(uN%;Ce!F|D*_<1b1K zL-}vOBuD)-vepQ*_GV9~7N6m7xxa1OAAZsK*ZQHom1h4o^77C8dgX8xlYiPsc?2J3 zb@U@?&tU2QORN7kqES-S6_}9!|4$R$|3|U^})9z5THn`&lVi_Q#g}aUu4{+4i&M?GGjC zQ=vv*<+7iZ>`Bzb8)obeE&Ex^ezq91&+Yb``x6>v!+f$4qkpbl0&2k6$*;j{+osz-+$?nxi|B_f8&eSISA35mH6oRn_; z75=tw@A9hFKr%K$C#%!+OEFr_rqVj z*U6n(6ZlfKyiq@T8Z5HYGtUK8sj&S=8T&5`#n^wz_a7Bv|5fb%mGQEFqfq;=Yi(o0 zU)t;?OQv4m{t-1`V%pVi_zl=Fwe)pXHJ=I6P`Rm2!-ZriA%Rg!u R_@!!5(xJ@z7mH=({~ttuNJIbt diff --git a/Implab/Diagnostics/IEventListener.cs b/Implab/Diagnostics/IEventListener.cs new file mode 100644 --- /dev/null +++ b/Implab/Diagnostics/IEventListener.cs @@ -0,0 +1,11 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading.Tasks; + +namespace Implab.Diagnostics { + public interface IEventListener { + void TraceEvent(LogContext context, TraceEventType type, string format, params object[] args); + } +} diff --git a/Implab/Diagnostics/Log.cs b/Implab/Diagnostics/Log.cs new file mode 100644 --- /dev/null +++ b/Implab/Diagnostics/Log.cs @@ -0,0 +1,50 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Text; +using System.Threading.Tasks; + +namespace Implab.Diagnostics { + public static class Log { + [Conditional("TRACE")] + public static void Transfer(LogContext from) { + LogContext.Transfer(from); + } + + [Conditional("TRACE")] + public static void StartLogicalOperation() { + LogContext.Current.StartLogicalOperation(); + } + + [Conditional("TRACE")] + public static void StartLogicalOperation(string name) { + LogContext.Current.StartLogicalOperation(name); + } + + [Conditional("TRACE")] + public static void EndLogicalOperation() { + LogContext.Current.EndLogicalOperation(); + } + + [Conditional("TRACE")] + public static void TraceInformation(string format, params object[] arguments) { + LogContext.Current.TraceEvent(TraceEventType.Information, format, arguments); + } + + [Conditional("TRACE")] + public static void TraceWarning(string format, params object[] arguments) { + LogContext.Current.TraceEvent(TraceEventType.Warning, format, arguments); + } + + [Conditional("TRACE")] + public static void TraceError(string format, params object[] arguments) { + LogContext.Current.TraceEvent(TraceEventType.Error, format, arguments); + } + + [Conditional("TRACE")] + public static void TraceError(Exception err) { + TraceError("{0}", err); + } + } +} diff --git a/Implab/Diagnostics/LogContext.cs b/Implab/Diagnostics/LogContext.cs new file mode 100644 --- /dev/null +++ b/Implab/Diagnostics/LogContext.cs @@ -0,0 +1,107 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading; +using System.Threading.Tasks; + +namespace Implab.Diagnostics { + public class LogContext { + LogicalOperation m_currentOperation; + readonly LogicalOperation m_traceBound; + readonly int m_threadId; + readonly LogContext m_parent; + + readonly static object _consoleLock = new object(); + + [ThreadStatic] + static LogContext _current; + + public static LogContext Current { + get { + if (_current == null) + _current = new LogContext(); + return _current; + } + } + + LogContext(LogContext context) { + if (context == null) + throw new ArgumentNullException("context"); + + m_parent = context; + m_currentOperation = context.CurrentOperation; + m_traceBound = context.CurrentOperation; + m_threadId = Thread.CurrentThread.ManagedThreadId; + + TraceEvent(TraceEventType.Transfer, String.Empty); + } + + LogContext() { + m_currentOperation = new LogicalOperation(); + m_traceBound = m_currentOperation; + m_threadId = Thread.CurrentThread.ManagedThreadId; + } + + public static void Transfer(LogContext from) { + _current = from == null ? new LogContext() : new LogContext(from); + } + + public LogContext ParentContext { + get { + return m_parent; + } + } + + public LogicalOperation CurrentOperation { + get { + return m_currentOperation; + } + } + + public LogicalOperation TraceBound { + get { + return m_traceBound; + } + } + + public int ThreadId { + get { + return m_threadId; + } + } + + public void StartLogicalOperation() { + StartLogicalOperation(null); + } + + public void StartLogicalOperation(string name) { + TraceEvent(TraceEventType.OperationStarted, "{0}", name); + m_currentOperation = new LogicalOperation(name, m_currentOperation); + } + + public void EndLogicalOperation() { + if (m_traceBound == m_currentOperation) { + TraceEvent(TraceEventType.Error, "Trying to end the operation which isn't belongs to current trace"); + } else { + var op = m_currentOperation; + m_currentOperation = m_currentOperation.Parent; + TraceEvent(TraceEventType.OperationCompleted, "{0} {1} ms", op.Name, op.Duration); + } + } + + public void TraceEvent(TraceEventType type, string format, params object[] args) { + /*var msg = new StringBuilder(); + for (int i = 0; i < CurrentOperation.Level; i++) + msg.Append(" "); + msg.Append(type); + msg.AppendFormat("[{0}]: ",m_threadId); + msg.AppendFormat(format, args); + + lock (_consoleLock) { + Console.ForegroundColor = (ConsoleColor)(m_threadId % 15 + 1); + Console.WriteLine(msg.ToString()); + }*/ + } + } +} diff --git a/Implab/Diagnostics/LogicalOperation.cs b/Implab/Diagnostics/LogicalOperation.cs new file mode 100644 --- /dev/null +++ b/Implab/Diagnostics/LogicalOperation.cs @@ -0,0 +1,47 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading.Tasks; + +namespace Implab.Diagnostics { + public class LogicalOperation { + readonly LogicalOperation m_parent; + readonly string m_name; + readonly int m_level; + readonly int m_timestamp; + + public LogicalOperation() + : this(null, null) { + } + + public LogicalOperation(string name, LogicalOperation parent) { + m_name = name ?? String.Empty; + m_parent = parent; + + m_level = parent == null ? 0 : parent.Level + 1; + m_timestamp = Environment.TickCount; + } + + public int Duration { + get { + var dt = Environment.TickCount - m_timestamp; + return dt < 0 ? int.MaxValue + dt : dt; // handle overflow + } + } + + public LogicalOperation Parent { + get { + return m_parent; + } + } + + public int Level { + get { return m_level; } + } + + public string Name { + get { return m_name; } + } + } +} diff --git a/Implab/Diagnostics/TraceEventType.cs b/Implab/Diagnostics/TraceEventType.cs new file mode 100644 --- /dev/null +++ b/Implab/Diagnostics/TraceEventType.cs @@ -0,0 +1,16 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using System.Threading.Tasks; + +namespace Implab.Diagnostics { + public enum TraceEventType { + Information = 1, + Warning, + Error, + OperationStarted, + OperationCompleted, + Transfer + } +} diff --git a/Implab/Implab.csproj b/Implab/Implab.csproj --- a/Implab/Implab.csproj +++ b/Implab/Implab.csproj @@ -15,7 +15,7 @@ full false bin\Debug - DEBUG; + TRACE;DEBUG; prompt 4 false @@ -32,6 +32,11 @@ + + + + + @@ -43,7 +48,6 @@ - diff --git a/Implab/Parallels/AsyncPool.cs b/Implab/Parallels/AsyncPool.cs --- a/Implab/Parallels/AsyncPool.cs +++ b/Implab/Parallels/AsyncPool.cs @@ -1,3 +1,4 @@ +using Implab.Diagnostics; using System; using System.Threading; @@ -13,8 +14,10 @@ namespace Implab.Parallels { public static Promise Invoke(Func func) { var p = new Promise(); + var caller = LogContext.Current; ThreadPool.QueueUserWorkItem(param => { + Log.Transfer(caller); try { p.Resolve(func()); } catch(Exception e) { @@ -28,7 +31,10 @@ namespace Implab.Parallels { public static Promise InvokeNewThread(Func func) { var p = new Promise(); + var caller = LogContext.Current; + var worker = new Thread(() => { + Log.Transfer(caller); try { p.Resolve(func()); } catch (Exception e) { diff --git a/Implab/Parallels/WorkerPool.cs b/Implab/Parallels/WorkerPool.cs --- a/Implab/Parallels/WorkerPool.cs +++ b/Implab/Parallels/WorkerPool.cs @@ -4,6 +4,7 @@ using System.Linq; using System.Text; using System.Threading; using System.Diagnostics; +using Implab.Diagnostics; namespace Implab.Parallels { public class WorkerPool : DispatchPool { @@ -41,7 +42,10 @@ namespace Implab.Parallels { var promise = new Promise(); + var caller = LogContext.Current; + EnqueueTask(delegate() { + Log.Transfer(caller); try { promise.Resolve(task()); } catch (Exception e) { diff --git a/Implab/PromiseState.cs b/Implab/PromiseState.cs deleted file mode 100644 --- a/Implab/PromiseState.cs +++ /dev/null @@ -1,15 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Linq; -using System.Text; - -namespace Implab -{ - public enum PromiseState - { - Unresolved, - Resolved, - Cancelled, - Rejected - } -}