Note
Access to this page requires authorization. You can try signing in or changing directories.
Access to this page requires authorization. You can try changing directories.
Question
Tuesday, July 14, 2020 6:26 PM
I have a winforms application that i am developing that needs to do some logging. In the event that we connect to our database we need to log a number of things one of which is a stacktrace just in case something goes wrong e.g.:
7/14/2020 10:02:31 AM
Success writing to the FM database, wrote PUDO request for the Edgebander
at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
at System.Environment.get_StackTrace()
at ModbusServer__Katalyn_.logger.log(String logMessage) in C:\Users\Ben deVries\source\repos\ModbusServer (Katalyn)\ModbusServer (Katalyn)\logger.cs:line 46
at ModbusServer__Katalyn_.subscriptionFunctions.pudo.edgebander() in C:\Users\Ben deVries\source\repos\ModbusServer (Katalyn)\ModbusServer (Katalyn)\subscriptionFunctions.cs:line 27
at ModbusServer__Katalyn_.ModbusServer.coilsChanged(Int32 coil, Int32 count) in C:\Users\Ben deVries\source\repos\ModbusServer (Katalyn)\ModbusServer (Katalyn)\ModbusServer.cs:line 160
at ModbusServer.WriteSingleCoil(ModbusProtocol receiveData, ModbusProtocol sendData, NetworkStream stream, Int32 portIn, IPAddress ipAddressIn)
at ModbusServer.CreateAnswer(ModbusProtocol receiveData, ModbusProtocol sendData, NetworkStream stream, Int32 portIn, IPAddress ipAddressIn)
at ModbusServer.ProcessReceivedData(Object networkConnectionParameter)
at TCPHandler.ReadCallback(IAsyncResult asyncResult)
at System.Net.LazyAsyncResult.Complete(IntPtr userToken)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Net.ContextAwareResult.Complete(IntPtr userToken)
at System.Net.LazyAsyncResult.ProtectedInvokeCallback(Object result, IntPtr userToken)
at System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)
I am hoping to be able to get the values of the variables passed into the functions (specifically my functions). and be able to get something like this:
7/14/2020 10:02:31 AM
Success writing to the FM database, wrote PUDO request for the Edgebander
at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
at System.Environment.get_StackTrace()
at ModbusServer__Katalyn_.logger.log(some string data) in C:\Users\Ben deVries\source\repos\ModbusServer (Katalyn)\ModbusServer (Katalyn)\logger.cs:line 46
at ModbusServer__Katalyn_.subscriptionFunctions.pudo.edgebander() in C:\Users\Ben deVries\source\repos\ModbusServer (Katalyn)\ModbusServer (Katalyn)\subscriptionFunctions.cs:line 27
at ModbusServer__Katalyn_.ModbusServer.coilsChanged(some int, some int) in C:\Users\Ben deVries\source\repos\ModbusServer (Katalyn)\ModbusServer (Katalyn)\ModbusServer.cs:line 160
at ModbusServer.WriteSingleCoil(some protocol, some protocol, some network stream, some int, some IP address)
at ModbusServer.CreateAnswer(some protocol, some protocol, some network stream, some int, some IP address)
at ModbusServer.ProcessReceivedData(some object)
at TCPHandler.ReadCallback(some IAsyncResult)
at System.Net.LazyAsyncResult.Complete(IntPtr userToken)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Net.ContextAwareResult.Complete(IntPtr userToken)
at System.Net.LazyAsyncResult.ProtectedInvokeCallback(Object result, IntPtr userToken)
at System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)
I don't care about values to or from code that is part of the .NET library. My code is very deterministic, as such knowing the variables if something fails will allow us to fix whatever issue may arise.
Any clue how to do this?
Is there some param i can pass into the stacktrace function to get these?
I have heard that System.Reflection might be useful, is that the case?
Thanks in advance,
Ben
All replies (6)
Wednesday, July 15, 2020 2:58 PM ✅Answered
I tend to disagree with dynamic logs outside of exception handling. I think the correct approach is to actually log the exact message you want instead. The reason I believe this is because only the function itself knows the importance of the variables and what they mean. For example imagine this call.
void Foo ( SomeData data )
{
}
void Foo ( DateTime data )
{
}
void Foo ( Form data )
{
}
In the first overload you might want all the values of the complex object. In the second overload you probably just want the string representation. In the third you likely don't need anything other than maybe the type. Having an explicit log at the top of the methods makes the most sense to me even if it adds a little work.
If you really want to automate this then reflection isn't useful here. Reflection fetches metadata. While you can get a property/field value from an instance a method call is just a temporary stack frame so there is no way to extract that via reflection. You can use StackFrame to get the current call but it doesn't have the argument values. It only gives you the IL which means you'd have to IL parsing. And StackFrame is expensive to create anyway.
There is also the Caller Information available in C# that can auto generate caller information. However it won't give you the arguments on the stack either.
Michael Taylor http://www.michaeltaylorp3.net
Wednesday, July 15, 2020 6:33 PM ✅Answered
Instead of smaller logs, maybe you can store the values to some global (static) variables, or to members of a special global object, associated with logging. Since you have threads, then use [ThreadStatic] attribute or ThreadLocal class. Not suitable for recursive functions, though, without adjustments. In case of objects, use try-finally to free the stored objects.
Then your logger, after extracting the stack trace, will also log these recorded values.
Wednesday, July 15, 2020 6:59 AM
Hi Navylsland,
Thank you for posting here.
We can get the name of the method that caused the exception and the parameter name of these methods through reflection.
try
{
//...;
}
catch (Exception ex)
{
StackTrace stackTrace = new StackTrace(ex);
var frames = stackTrace.GetFrames();
MethodBase methodBase = frames[0].GetMethod();
ParameterInfo[] parameterInfos = methodBase.GetParameters();
But if you want to get the values of these parameters, it may be much harder.
See if the method mentioned in this link is helpful to you.
Can I get parameter names/values procedurally from the currently executing function?
Best Regards,
Timon
MSDN Community Support
Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact [email protected].
Wednesday, July 15, 2020 5:48 PM
Hi Michael,
As a general rule i would agree with the observation that we may have method overloading and as such it may be difficult to read some of the logs. However, all of our custom objects have a 'stringify' function which overrides the .ToString() method making reverse parsing quite simple and easy.
The main reason that i didn't want to do many smaller logs where you log whatever is needed at the time is because the project is heavily multithreaded (not uncommon for 20-35 threads to be actively running). As such, the stacktrace route made sense in that it allowed me to get the data from a single thread without having multiple threads logs interwoven.
Wednesday, July 15, 2020 7:08 PM
I will give that a shot, thanks.
Wednesday, July 15, 2020 7:24 PM
I don't agree that you should be relying on the thread for anything related to logging. It is too limiting. Assuming that each thread is an isolated piece of code (for purposes of logging) is not correct if you are using async code which will frequently be bouncing around threads. 20-30 threads actually isn't a lot in my world. I manage a lot of web apps and we can have 100s of requests (threads) running simultaneously. The threads aren't the important part, it's the context.
If you want to track work as it flows through your functions then you should really consider using a correlation ID instead. .NET even ships with one via the CorrelationManager although you might find your own better. By passing the correlation ID (or any unique identifier) through functions (which generally means they have to be built for it) you can see how a single request moves between threads and functions and not just the functions themselves.
Your code paths seem to indicate you're talking to a ModBus PLC so you may not have the threading issues we have in web apps. Most likely your PLC requires sequential access anyway (unless you're using OPC perhaps) but historically when I worked with PLCs we always did that on a single, dedicated thread so we didn't have to worry about synchronization issues as much. Other code called a PLC wrapper class that helped ensure ordering and behavior. So using the threads for tracking wouldn't work well there. But your mileage may vary.
Michael Taylor http://www.michaeltaylorp3.net