Mystery "missing milliseconds": calling ActiveX from VB.Net sometimes takes 15ms !!??
Posting here because I think it might be related to .Net runtime or Interop wrappers for unmanaged C++/MFC COM controls:
Background: I have an ActiveX/COM control written in C++/MFC which processes video (ie. 30 frames per second => about 33ms per frame processing budget) Various rendering aspects of the control can be modified using Set calls on the control, which clients can issue at any time.
It turns out that someone (Windows scheduler, .Net interop wrappers, MFC call dispatcher, memory allocator, garbage disposal ?) is quite frequently eating an incredibly long 15.625ms to make or return from the call into the control. Thats half my per-frame budget eaten by some gremlins in the runtime !
The control itself is - for historical reasons - written in C++/MFC. The problem happens when the control is called from C# as well as VB.Net. It happens on very different hardware (an HP Pavilion 2.8Ghz Pentium D, a Macbook Pro with 2.5 Ghz Intel Core 2 Duo running Parallels VM). Just how often this mystery hiccup of 15.625ms occurs differs between machines, but when it does, it is always 15.625ms exactly. Strange.
I have made a rather minimal test case that strips out all the video processing etc.
First, I created an MFC/COM Control project in the Project Wizard of Visual Studio 2003 and left things at their default settings (Apartment threading etc.). Then I added a single user defined call TestCall() to the control which does nothing (manually since there is no more classwizard)
Then I created a VB Client program which instantiates the control. It endlessly calls the TestTiming() sub which times how long a single call into the control takes and prints out that time.
The TestTiming call basically just does this:
I print out calls that take 0 ms (well something less than 1ms anyway) as "." and for calls > 0ms I print out the actual ms. The output looks something like this:
startTime = DateTime.Now
Dim h = AxTestControl1.TestCall()
endTime = DateTime.Now
Dim ms As integer = endTime.Subtract(startTime).TotalMilliseconds
So some variable nr of calls that execute quickly, as desired, and then a "hiccup" call that always takes the exact same amount of time (15.625ms), then some more quick calls.
If instead of the user defined control function .TestCall() inside the timing I use a standard control property, like
or a built in control method like
Dim h = AxTestControl1.Height
Then I never, ever get a hiccup call.
Dim h = AxTestControl1.ToString()
On different machines you will get a different average number of "." before a hiccup but even then the hiccup is 15.625ms
I should mention that the sample code spins off a background thread and calls the TimingTest from its ThreadTask(). This is the way the bug was originally reported to me. However, I can put the
right in the main UI thread - as the first thing in Form1_Load() for example. And it will exhibit the same behaviour, except there will be substantially more good=0ms="." calls on average between the inevitable hiccups.
I *think* my timing test methodology is correct (?) And the fact that standard control properties and functions never hiccup indicate that the hiccups are not an artefact of my test setup, but related to a dispatched call into a user-defined function of the control.
Anybody have an idea what is going on and how I can prevent the far too frequent eating of half my per-frame processing budget by the runtime ?
I bow in gratitude for any advice
Visual Studio 2003 .Net 1.1
Windows XP Pro SP2
Complete Form1.vb of the VB Client:
And the C++ component itself (it has quite a few automatically generated files, I show only what I think is most relevant here - ie changes from the boilerplate code from the MFC ActiveX Control C++ project template):
Public Class Form1
#Region " Windows Form Designer generated code "
Private fMyThread As Thread
Private Sub Form1_Load(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles MyBase.Load
' to see the hiccup on the main UI thread, put the Do/TestTiming()/Loop here
fMyThread = New Thread(AddressOf ThreadTask)
Private Sub ThreadTask()
Private Sub TestTiming()
Dim startTime, endTime As System.DateTime
startTime = DateTime.Now
Dim h = AxTestControl1.TestCall() ' user defined control methods do cause frequent hiccups of 15.625ms
'Dim h = AxTestControl1.ToString() ' standard control properties and method never cause a hiccup
endTime = DateTime.Now
Dim ms As Double = endTime.Subtract(startTime).TotalMilliseconds
If (ms > 0) Then
Console.WriteLine(ms & " ms")
Static n As Integer = 0
n += 1
If (n Mod 80 = 0) Then Console.WriteLine("")
TestControlCtrl.cpp (I added the TestCall declaration and implementation, analogously in TestControlCtrl.h, not shown here)
....unmodified boilerplate code here
// Dispatch map
DISP_FUNCTION_ID(CTestControlCtrl, "AboutBox", DISPID_ABOUTBOX, AboutBox, VT_EMPTY, VTS_NONE)
DISP_FUNCTION(CTestControlCtrl, "TestCall", TestCall, VT_I2, VTS_NONE)
....unmodified boilerplate code here
// CTestControlCtrl message handlers
short CTestControlCtrl::TestCall( void )
return 0; // do nothing
TestControl.idl (I added the line with TestCall in it)
I attach the full sourcecode (Visual Studio solutions) for both the testing control and the VB.Net client code calling it.
[ uuid(6E23484D-00D2-4500-A149-BF20F088CE00), version(1.0),
helpstring("TestControl ActiveX Control module"),
// Primary dispatch interface for CTestControlCtrl
helpstring("Dispatch interface for TestControl Control")]
[id(DISPID_ABOUTBOX)] void AboutBox();
[id(2)] int TestCall( void ); // I added this for my test
...etc. (rest unchanged)
Did you ever resolve this issue? I'm experiencing the same thing, exactly 15 milliseconds ‘extra’ every x calls to an external .dll. Its always 15 milliseconds. The only significant difference is I’m accessing an external win32 .dll via P-invoke (dllimport), not via ActiveX. My dll was also created with C++, however another difference is my .dll is not using MFC. My function which makes the dll call also runs inside a thread spawned off the main app (and you mentioned even if you make the call directly from the main app you still experience the problem, as do I). In my case I’m creating a lather large StringBuilder which is passed byRef to the .dll, and used to collect the .dll output. If I bypass the .dll call, but still create the large StringBuilder, I still experience the mystery 15 milliseconds, however interestingly instead of occurring during the .dll call (which is no longer being made), it occurs around processing the StringBuilder (either initializing it or other processing steps surrounding it). If I eliminate both the .dll call and the instantiating the StringBuilder, only then does the mystery 15 milliseconds disappear.
My project is VS2008, another difference from what you’re running. Like you, I’m thinking memory allocator or Garbage Collector. Did you ever find the cause? Did you find a solution? I’m a department of one and battling several projects at once, so any assistance is greatly appreciated.
15 milliseconds is not a mystery. It is the precision of the timer in modern computers. More precisely, it is around 15.6, probably the 15.625 stated in the first post of this thread.
Since the framework gets its time from that clock, it cannot be more precise than that.
When you get 15ms, the real time can be anywhere between 1 and 15 ms.
Take the following code:
Although the thread slept only 1 ms, the result is 15 ms.
Dim d As Date = Date.Now
Sleep for 15 and you get 15
Sleep for 16 and you get 31
Any measurement you do between 2 DateTime values will always be in increments of something around 15.6.
I think I remember reading something about getting timing values from the microprocessor instead of the clock, which make things more precise.
You might want to give a look at the PerformanceCounter class. I personnally never had need to go that precise, so I never used that class, but it was designed for the purpose of checking performance, and could thus be more precise that the standard DateTime functions.
By Patrick Troughton in forum .NET
Last Post: 08-13-2002, 12:18 PM
By Dan Barclay in forum .NET
Last Post: 08-12-2002, 11:06 PM
Tags for this Thread
Top DevX Stories
Easy Web Services with SQL Server 2005 HTTP Endpoints
JavaOne 2005: Java Platform Roadmap Focuses on Ease of Development, Sun Focuses on the "Free" in F.O.S.S.
Wed Yourself to UML with the Power of Associations
Microsoft to Add AJAX Capabilities to ASP.NET
IBM's Cloudscape Versus MySQL