Application consumes close to 100% of CPU, how to profile and determine the cause

[LordHog]

Hello,

I recently wrote an application that is used for testing units in a
burn-in chamber. It uses two external library that require the use of
P\Invoke in order to work with them. There is a primary thread and a
secondary polling thread. Every once in a while the process will
consume close to 100% of the CPU, but I am unclear why. I am wondering
how would I go about determine the cause of the problem? What sort of
tools or instrumentation should I use in order to determine what part
of the code is causing the problem. Any help is greatly appreciated.

I know in the hardware world I could implement a watchdog to restart
the sytem, would something like that be useful? I would have to keep
track of the system thus is would run slower and consume more
resources, but I might be able to recover when the process has
problems???

Mark

[Nicholas Paldino [.NET/C# MVP]]

Mark,

Are you finding that these spikes are impacting the performance of the
application, or, the performance of the machine overall?

It's very possible that the spikes could be the result of garbage
collection and memory management.
--
- Nicholas Paldino [.NET/C# MVP]
- mv*@spam.guard.caspershouse.com

<Lo*****@hotmail.com> wrote in message
news:11**********************@z14g2000cwz.googlegr oups.com...

Hello,

I recently wrote an application that is used for testing units in a
burn-in chamber. It uses two external library that require the use of
P\Invoke in order to work with them. There is a primary thread and a
secondary polling thread. Every once in a while the process will
consume close to 100% of the CPU, but I am unclear why. I am wondering
how would I go about determine the cause of the problem? What sort of
tools or instrumentation should I use in order to determine what part
of the code is causing the problem. Any help is greatly appreciated.

I know in the hardware world I could implement a watchdog to restart
the sytem, would something like that be useful? I would have to keep
track of the system thus is would run slower and consume more
resources, but I might be able to recover when the process has
problems???

Mark

[LordHog]

Nicholas,

Sorry that I didn't explain myself well enough. Actually when the
process consumes close to 100% of the CPU it stays at that level until
I kill the task. I have let it run a few minutes to see if it would
recover, but it never did so I killed the task. I am unclear what is
triggering it.

For the P/Invoke functions they look like the following

[DllImport("SiF32xUSB.DLL", EntryPoint = "F32x_Write", SetLastError
= true,
CharSet = CharSet.Unicode, ExactSpelling = true,
CallingConvention = CallingConvention.StdCall)]
private static extern
System.Int32 F32x_Write( System.UInt32 Handle,
System.IntPtr Buffer,
System.UInt32 NumBytesToRead,
ref System.UInt32
NumBytesWrittenToDevice
);

Then the correspond method that uses this function is as follows:

public bool Write( UInt32 handle, byte[] buffer )
{
UInt32 numBytesWritten = 0x00;

GCHandle gch = GCHandle.Alloc( buffer, GCHandleType.Pinned );

m_LastErrorCode =
(SI_RETURN_CODES)F32x_Write( handle,
gch.AddrOfPinnedObject(),
(UInt32)buffer.Length,
ref numBytesWritten );

gch.Free();

if ( m_LastErrorCode == SI_RETURN_CODES.SI_SUCCESS )
{
return true;
}
else
{
return false;
}
}

I don't know if either of these declarations are causing the problems
or not. I did notice I do have one P/Invoke function to where the
memory isn't pinned therefore perhaps the GC is executing at that
particular time and causing the problem. That method looks like

public MMCThermocoupleTypes TCType
{
get { return m_TCType; }
set
{
int apiResult;

try
{
m_TCType = value;
apiResult = cbSetConfig( (int)MCCCfgInfpType.BOARDINFO,
(int)m_USBTCBoardNum,
(int)m_ChamberTCChannel,

(int)MMMBoardCfgInfoType.BITCCHANTYPE,
(int)m_TCType
);
}
catch ( Exception )
{
// TODO: Implement handler for this event.
}
}
}

The variables that start with "m_" are members to the class and are
private. Perhaps the GC is moving memory around at this particular
point in time causing problems? I really don't know.

Mark

[Nicholas Paldino [.NET/C# MVP]]

From what I can see, you don't need to pin the byte array before passing
it to your unamanged code. The marshaler will pin the array in memory for
you, and release it when done.

As for the spike, there is nothing here that I would see that would
cause this, as you are releasing the pinned variable. Does your application
not respond during this time? You haven't given any indication that 100%
utilization is impacting your app, or the machine negatively.

--
- Nicholas Paldino [.NET/C# MVP]
- mv*@spam.guard.caspershouse.com

<Lo*****@hotmail.com> wrote in message
news:11**********************@g14g2000cwa.googlegr oups.com...

Nicholas,

Sorry that I didn't explain myself well enough. Actually when the
process consumes close to 100% of the CPU it stays at that level until
I kill the task. I have let it run a few minutes to see if it would
recover, but it never did so I killed the task. I am unclear what is
triggering it.

For the P/Invoke functions they look like the following

[DllImport("SiF32xUSB.DLL", EntryPoint = "F32x_Write", SetLastError
= true,
CharSet = CharSet.Unicode, ExactSpelling = true,
CallingConvention = CallingConvention.StdCall)]
private static extern
System.Int32 F32x_Write( System.UInt32 Handle,
System.IntPtr Buffer,
System.UInt32 NumBytesToRead,
ref System.UInt32
NumBytesWrittenToDevice
);

Then the correspond method that uses this function is as follows:

public bool Write( UInt32 handle, byte[] buffer )
{
UInt32 numBytesWritten = 0x00;

GCHandle gch = GCHandle.Alloc( buffer, GCHandleType.Pinned );

m_LastErrorCode =
(SI_RETURN_CODES)F32x_Write( handle,
gch.AddrOfPinnedObject(),
(UInt32)buffer.Length,
ref numBytesWritten );

gch.Free();

if ( m_LastErrorCode == SI_RETURN_CODES.SI_SUCCESS )
{
return true;
}
else
{
return false;
}
}

I don't know if either of these declarations are causing the problems
or not. I did notice I do have one P/Invoke function to where the
memory isn't pinned therefore perhaps the GC is executing at that
particular time and causing the problem. That method looks like

public MMCThermocoupleTypes TCType
{
get { return m_TCType; }
set
{
int apiResult;

try
{
m_TCType = value;
apiResult = cbSetConfig( (int)MCCCfgInfpType.BOARDINFO,
(int)m_USBTCBoardNum,
(int)m_ChamberTCChannel,

(int)MMMBoardCfgInfoType.BITCCHANTYPE,
(int)m_TCType
);
}
catch ( Exception )
{
// TODO: Implement handler for this event.
}
}
}

The variables that start with "m_" are members to the class and are
private. Perhaps the GC is moving memory around at this particular
point in time causing problems? I really don't know.

Mark

[LordHog]

Nicholas,

The application under normal load appears to use anywhere from 25 to
50 megs of memory and about ~5% CPU utilization. When the application
peaks and holds near 100% CPU utilitization the GUI is unresponsive,
the cursor changes to an hour-glass indicating it is awaiting for
something to complete. If you try to move the GUI it will move, but
application window is never redrawn. So I would guess this is the
negative impact that you are looking for.

Thanks for the information regarding the marshaler will pin the array
down as I didn't know that. I assume that I needed to do that myself. I
did fail to state that I am using Visual C# 2005 Express Beta. I am
using this because I also need to use the new Serial Port class as v1.x
didn't include it.

Right now the application is running in the lab and has behaved good
for the past three hours. I can't seem to predict what causes the spike
as it might happen just after launching the application or five minutes
after running it.

Mark

[Ollie Riches]

Mark,

You can use performance monitor (perf mon) in 'Administrator Tools' to get a
view out what is going in your application. It has alot of .Net related
counters that include one for monitoring memory activates.

HTH

Ollie Riches

<Lo*****@hotmail.com> wrote in message
news:11**********************@o13g2000cwo.googlegr oups.com...

Nicholas,

The application under normal load appears to use anywhere from 25 to
50 megs of memory and about ~5% CPU utilization. When the application
peaks and holds near 100% CPU utilitization the GUI is unresponsive,
the cursor changes to an hour-glass indicating it is awaiting for
something to complete. If you try to move the GUI it will move, but
application window is never redrawn. So I would guess this is the
negative impact that you are looking for.

Thanks for the information regarding the marshaler will pin the array
down as I didn't know that. I assume that I needed to do that myself. I
did fail to state that I am using Visual C# 2005 Express Beta. I am
using this because I also need to use the new Serial Port class as v1.x
didn't include it.

Right now the application is running in the lab and has behaved good
for the past three hours. I can't seem to predict what causes the spike
as it might happen just after launching the application or five minutes
after running it.

Mark

[LordHog]

Ollie,

I will check the perfmon msc tomorrow and hopefully it will lead to a
solution. I was checking the process using sysinternals process
explorer, but I wasn't seeing anything that would give me a clue or I
wasn't reading the data correctly.

Since there are a ton of items that I can monitor, do you (or anyone
else) have an idea of what items I should zero in on for the first go
around?

Mark

[ollie.riches]

check out the '.Net memory' counters these will give you some info
about what is going on with memory allocation and GC

Ollie Riches

[LordHog]

Ollie and Nicholas,

Okay, I ran the perfmon against the assembly, but I really don't see
anything that my eyes can detect what might be the problem. I am not
sure how to interpret the log effectively. There were the items that I
monitored

"\.NET CLR Interop(SDU ATP-BurnIn)\# of CCWs",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of marshalling",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of Stubs",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of TLB exports / sec",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of TLB imports / sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of current logical
Threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of current physical
Threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of current recognized
threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of total recognized
threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Contention Rate / sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Current Queue Length",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Queue Length / sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Queue Length Peak",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\rate of recognized threads /
sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Total # of Contentions",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Bytes in all Heaps",
"\.NET CLR Memory(SDU ATP-BurnIn)\# GC Handles",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Gen 0 Collections",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Gen 1 Collections",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Gen 2 Collections",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Induced GC",
"\.NET CLR Memory(SDU ATP-BurnIn)\# of Pinned Objects",
"\.NET CLR Memory(SDU ATP-BurnIn)\# of Sink Blocks in use",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Total committed Bytes",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Total reserved Bytes",
"\.NET CLR Memory(SDU ATP-BurnIn)\% Time in GC",
"\.NET CLR Memory(SDU ATP-BurnIn)\Allocated Bytes/sec",
"\.NET CLR Memory(SDU ATP-BurnIn)\Finalization Survivors",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 0 heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 0 Promoted Bytes/Sec",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 1 heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 1 Promoted Bytes/Sec",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 2 heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Large Object Heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Finalization-Memory from Gen
0",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Finalization-Memory from Gen
1",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Memory from Gen 0",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Memory from Gen 1",
"\Process(SDU ATP-BurnIn)\% Privileged Time",
"\Process(SDU ATP-BurnIn)\% Processor Time",
"\Processor(_Total)\% Processor Time"

I did see pattern develop, but I didn't see a pattern when the
application consumed all the processor time. If any one cares to look
at the log that was captured you can find it here...

http://www.liquid-minds.com/SDU_BurnIn_000002.csv

It is case sensitive. I am not sure what else I should capture. I am
not 100% sure, but I think the problem is in the area with the interop
service. If I disconnect the two external USB devices I don't see the
problem or at least been able to induce it. In order to induce the
problem there is no cookbook method, I just click between windows,
minimize, maximize etc and wait for the application to consume all the
CPU time.

Mark

[Ollie Riches]

Mark,
FYI - the microsoft.public.dotnet.framework.performance newsgroup is the
best place for performance related questions.

Ollie

<Lo*****@hotmail.com> wrote in message
news:11**********************@g44g2000cwa.googlegr oups.com...

Ollie and Nicholas,

Okay, I ran the perfmon against the assembly, but I really don't see
anything that my eyes can detect what might be the problem. I am not
sure how to interpret the log effectively. There were the items that I
monitored

"\.NET CLR Interop(SDU ATP-BurnIn)\# of CCWs",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of marshalling",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of Stubs",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of TLB exports / sec",
"\.NET CLR Interop(SDU ATP-BurnIn)\# of TLB imports / sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of current logical
Threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of current physical
Threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of current recognized
threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\# of total recognized
threads",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Contention Rate / sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Current Queue Length",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Queue Length / sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Queue Length Peak",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\rate of recognized threads /
sec",
"\.NET CLR LocksAndThreads(SDU ATP-BurnIn)\Total # of Contentions",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Bytes in all Heaps",
"\.NET CLR Memory(SDU ATP-BurnIn)\# GC Handles",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Gen 0 Collections",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Gen 1 Collections",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Gen 2 Collections",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Induced GC",
"\.NET CLR Memory(SDU ATP-BurnIn)\# of Pinned Objects",
"\.NET CLR Memory(SDU ATP-BurnIn)\# of Sink Blocks in use",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Total committed Bytes",
"\.NET CLR Memory(SDU ATP-BurnIn)\# Total reserved Bytes",
"\.NET CLR Memory(SDU ATP-BurnIn)\% Time in GC",
"\.NET CLR Memory(SDU ATP-BurnIn)\Allocated Bytes/sec",
"\.NET CLR Memory(SDU ATP-BurnIn)\Finalization Survivors",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 0 heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 0 Promoted Bytes/Sec",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 1 heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 1 Promoted Bytes/Sec",
"\.NET CLR Memory(SDU ATP-BurnIn)\Gen 2 heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Large Object Heap size",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Finalization-Memory from Gen
0",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Finalization-Memory from Gen
1",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Memory from Gen 0",
"\.NET CLR Memory(SDU ATP-BurnIn)\Promoted Memory from Gen 1",
"\Process(SDU ATP-BurnIn)\% Privileged Time",
"\Process(SDU ATP-BurnIn)\% Processor Time",
"\Processor(_Total)\% Processor Time"

I did see pattern develop, but I didn't see a pattern when the
application consumed all the processor time. If any one cares to look
at the log that was captured you can find it here...

http://www.liquid-minds.com/SDU_BurnIn_000002.csv

It is case sensitive. I am not sure what else I should capture. I am
not 100% sure, but I think the problem is in the area with the interop
service. If I disconnect the two external USB devices I don't see the
problem or at least been able to induce it. In order to induce the
problem there is no cookbook method, I just click between windows,
minimize, maximize etc and wait for the application to consume all the
CPU time.

Mark

[LordHog]

Ollie,

Should I move the question over to that newsgroup? I didn't think it
was a performance issue since I must have a bug in my software,
somewhere, which is causing my problems? If I move it over to the other
newsgroup will people consider is cross posting? I don't want to make
people upset as I do need help.

Mark

[LordHog]

Hello all, (yet again)

I recently noticed that I am able to cause the application to
eventually consume close to 100% of the CPU when I run the Released
version of the application. I have been unable so far to produce the
same behavior when executing the Debug version of the application.
Since I had never seen this problem while debugging the application. It
was just recently that I was running the application in a test
environment as a stand-a-lone application and outside visual studio.
Providing this problem only arises when running the release version, is
there a new direction I should focus my efforts in solving the problem?
Thanks

Mark