COM Control Call from .Net frequently blocking for 15(!!)ms ?

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:

Code:

---

    startTime = DateTime.Now
    Dim h = AxTestControl1.TestCall()
    endTime = DateTime.Now
    Dim ms As integer = endTime.Subtract(startTime).TotalMilliseconds

---

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:

.15.625 ms
.........15.625 ms
.........15.625 ms
.........15.625 ms
..........15.625 ms
..........15.625 ms
...........15.625 ms
..........15.625 ms
..........15.625 ms

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

Code:

---

Dim h = AxTestControl1.Height

---

or a built in control method like

Code:

---

Dim h = AxTestControl1.ToString()

---

Then I never, ever get a hiccup call.

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

Code:

---

Do
    TimingTest()
Loop

---

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 :)

Mr.Toad

Specs:
Visual Studio 2003 .Net 1.1
Windows XP Pro SP2

Complete Form1.vb of the VB Client:

Code:

---

Imports System.Threading

Public Class Form1
    Inherits System.Windows.Forms.Form
    #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)
        fMyThread.Start()
    End Sub

    Private Sub ThreadTask()
        Do
            TestTiming()
        Loop
    End Sub

    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")
        Else
            Static n As Integer = 0
            n += 1
            If (n Mod 80 = 0) Then Console.WriteLine("")
            Console.Write(".")
        End If
    End Sub
End Class

---

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):

TestControlCtrl.cpp (I added the TestCall declaration and implementation, analogously in TestControlCtrl.h, not shown here)

Code:

---

....unmodified boilerplate code here

// Dispatch map
BEGIN_DISPATCH_MAP(CTestControlCtrl, COleControl)
    DISP_FUNCTION_ID(CTestControlCtrl, "AboutBox", DISPID_ABOUTBOX, AboutBox, VT_EMPTY, VTS_NONE)
    DISP_FUNCTION(CTestControlCtrl, "TestCall", TestCall, VT_I2, VTS_NONE)
END_DISPATCH_MAP()

....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)

Code:

---

#include <olectl.h>
#include <idispids.h>

[ uuid(6E23484D-00D2-4500-A149-BF20F088CE00), version(1.0),
  helpfile("TestControl.hlp"),
  helpstring("TestControl ActiveX Control module"),
  control ]
library TestControlLib
{
    importlib(STDOLE_TLB);

    //  Primary dispatch interface for CTestControlCtrl

    [ uuid(E8A6BFC3-87DB-48DF-812A-2E79604C1AA3),
      helpstring("Dispatch interface for TestControl Control")]
    dispinterface _DTestControl
    {
        properties:
        methods:

            [id(DISPID_ABOUTBOX)] void AboutBox();
            [id(2)] int TestCall( void ); // I added this for my test
    };
...etc. (rest unchanged)

---

I attach the complete code for the two solutions (the activeX control and the VB client test program)