We're chasing our tails trying to figure out what is happening, but we are calling a .NET DLL from FoxPro using wwDotNetBridge. We have found very erratic behaviour where we are getting corrupted tables. Almost always the corruption looks similar to log4net output (we are using log4net in our .NET DLL).

I can post some more screen shots but I was wondering if anyone else has heard of/had issues using logging when calling .NET code from FoxPro? Ours is a very large application and we have dozens of simultaneous users.

Any help is appreciated, I can provide more detail if anyone would like.

A typical row that is corrupted:

That sounds like an issue with log.net. Only thing I can think of that database logging may not work with multiple separate instances and expects a static reference in the context of a single application but offhand I don't know. I would think any logging solution needs to be multi-thread/multi-user safe, so I can't imagine that the problem is concurrency, but that sure is what it looks like.

+++ Rick ---

At this point we're likely to just pull the logging. We can't reliably reproduce the error; about 95% of the time it works fine but very occasionally we get the behaviour shown in this post. It's frustrating but at this point we're not sure what else to try after all the different approaches we've taken.

I would try a different data provider like writing a log file (text) file to disk and see what that produces.

The other thing you can do is create a .NET method that is called from wwDotnetBridge perhaps with a simpler parameter signature and perhaps add some additional logging in there to log out the data that is actually being written out in the log calls. That will tell you whether the data going in is bad or whether it's indeed log.net that's mangling the data.

I just can't see anything that could account for the data corruption you see in that pic that could be caused by wwDotnetBridge. If calls were corrupting memory the CLR would end up with memory validation/count error that would cause outright exceptions and it almost certainly wouldn't be able to line up a parameter or property calls correctly to not fail on something like a date or numeric value. This looks more like a data transcription issues which might be happening inside of log.net or the specific provider you're using.

Either sounds really far fetched knowing that log.net is so widely used although I think the db logger is probably one of the less used features.

Also where are you using this from exactly? Is it in a Web site with a FoxPro DLL COM Server? There are a lot of scenarios that can cause data corruption in that scenario with data getting overwritten by FoxPro if you're not careful with concurrent/global state code in FoxPro.

+++ Rick ---

Here's the confusing part: the logs do write to a text file, not a db - that is why we're so stumped.

We're using the bridge with our legacy FoxPro software to do two things:

1. to make simple calls to a MSSQL database to retrieve simple data (as simple as it gets - just returns an int)

2. to call a REST endpoint. The endpoint is called with HttpClient.

Now here is another variable (no pun intended): there hasn't been any corruption at all with the first part (we have deployed this to production and have had zero problems (so far). It's only when the latter is called by several testers simultaneously that there are issues with data corruption. The corruption doesn't seem to have anything to do with API calls though, but as that is the only difference we're going to dive deeper.

A few things we're going to try:

• Remove the logging
• Change the HttpClient to call synchronously (this one hasn't been an issue and doesn't seem related to the logging but whatever, we'll try it)
• Remove all shared variables and force each method to be limited entirely to it's own scope. No globals, no singletons, no shared anything.
• I reaaaalllly don't want to do this, but have each instance of the FoxPro program make a copy of the bridge DLLs and use it's own copy. I can't see how this would possibly be a problem, but at this point I'm willing to try anything.

We're hoping one of these fixes it. I'd be pretty happy if we could keep our logging. It's our only view into troubleshooting in production but the two functions can only fail in a few ways so it's not the end of the world.

Trevor

Ah, you're using async calls with wwHttp? Yeah that is the likely cause. That code is not meant for many overlapping calls. That code path uses some really ancient Win32 C++ code path in wwIpstuff.dll that's basically hand coded thread code. It's quite possible that code is not entirely threadsafe and that could be the cause for the data corruption.

If that's the case making sync calls to the logging api might be the way to figure this out. And if that's indeed the case, you can use some of the helper .NET APIs that exist in wwDotnetBridge.dll - I believe Westwind.Utilities.InternetTools.HttpClient.

It's basically this class:

https://github.com/RickStrahl/Westwind.Utilities/blob/master/Westwind.Utilities/InternetTools/HttpClient.cs

which can be accessed with wwDotnetBridge and that has a stable async api. I probably should fix the async wwHttp version to use that instead (main reason it's not is because wwHttp otherwise doesn't have any external dependencies).

+++ Rick ---

If the calls were synchronous but being called by many simultaneous VFP instances do you think that would also be problematic? For instance let's say we have our FoxPro program, let's call it myFox.exe, being run by four signed in users (so there would be 4 myFox.exe in Processes in Task Manager). Each of those instances would open the DLL, let's call it bridge.DLL. If in bridge.DLL we were calling a REST endpoint synchronously by all four processes, do you think that could cause issues? (In other words simultaneous, not synchronous)

I would assume separate instances calling a DLL would be fine as long as they weren't overlapping file access but in this case they're just making synchronous web calls.

Thanks, Trevor

I just re-read your first message and I should clarify. We are not making any REST calls with wwHttp or directly in FoxPro. We are using the .NET DLL, called from FoxPro, to make our web calls.

Stripped out all the logging and we cannot reproduce the corruption. So definitely looks like log4net doesn't play nicely.

Any chance that the APIs you're calling are async? If that's the case there's a good possibility that if you're using sync->async->sync (ie. .Wait() or .Result) calls end up causing potential race conditions.

if doing that the trick is to leave the async routines to run async and use wwDotnetBridge's async call methods to let the async code run and return a result (or just completion) to ensure the Task instances clean up properly. The sync->async handling in .NET are terrible unfortunately as there are many ways to this but only 1 or 2 safe ways.

+++ Rick ---

Yep, our API calls are async calls that we are making sync by using .Result. I'll definitely take a look at what we can do there.

Thanks a lot for the feedback - will definitely help us re-introduce the code I stripped out. Trevor

Yup that most likely is the problem as .Result and .Wait() are highly unreliable in simultaneous call scenarios.

Code like the following can help:

var task = SomeFunctionAsync();
var result =  task.ConfigureAwait(false).GetAwaiter().GetResult();

as it removes the thread synchronization in the actual callback and leaves only the result retrieval code for potential deadlock (which is much less likely).

Ultimately though it's best to let the async code run and call back. If this code is getting called from wwDotnetBridge, make the entire method that's hosting your HTTP call (or the top level one that exposed to Fox) async and then use InvokeMethodAsync() in wwDotnetBridge.

wwDotnetBridge::InvokeTaskMethodAsync()

This actually hooks up a result handler to the task and then pushes the result into your FoxPro code via a callback (ie. it maintains the 'async' nature of the call into FoxPro).

+++ Rick ---