Visual Basic Code , VB.NET Code, VB Code
  Home   :  Code   :  Forums   :  Submit   :  Mailing List   :  About   :  Contact


Mystery Missing Milliseconds: why do calls into COM control often take 15.625 ms ?


Mystery Missing Milliseconds: why do calls into COM control often take...

Author
Message
rtvstoad
rtvstoad
Forum God
Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)Forum God (449 reputation)

Group: Forum Members
Posts: 1, Visits: 3
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:





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

Dim h = AxTestControl1.Height


or a built in control method like

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



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 Smile



Mr.Toad



Specs:

Visual Studio 2003 .Net 1.1

Windows XP Pro SP2



Complete Form1.vb of the VB Client:



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)



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



#include

#include



[ 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 two Visual Studio solutions for the test: one for the activeX control with the TestCall() function, the other for the VB.Net code that calls the COM control and times the calls.
Attachments
TestingCode.zip (2.1K views, 28.00 KB)
dilettante
dilettante
Forum God
Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)Forum God (3.6K reputation)

Group: Forum Members
Posts: 9, Visits: 54
Is there any VB6 question here at all?
Mark
Mark
Forum God
Forum God (139K reputation)

Group: Moderators
Posts: 1.1K, Visits: 11K
All I can tell you is 15.625ms is the smallest timeslice you can measure on your system the way you are measureing it. There may be a more precise way to measure but I'm not sure of that. This doesn't mean your process is taking the entire 15.625ms.
GO


Similar Topics


Reading This Topic


Login
Existing Account
Email Address:


Password:


Social Logins

Select a Forum....

















A1VBCode Forums


Search