J
Joe Kinsella
My application is a multi-threaded service that collects performance counter
data from a series of servers. These servers are located on different
networks with different speed links. Periodically, one or more of these
links can become very slow. The .Net related problem is that when one link
is slow, it causes all peformance counter collection to other targets - even
those on low latency local networks - to not respond even though they are
running in independent threads.
The data I have collected suggests there is a global lock being used
somewhere in the implementation of PerformanceCounter. From coredbg, I can
see all the threads are simultaneous "stuck"
PerformanceCounterLib:get_CategoryTable. For example, see the below:
Thread 0xd10 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1594 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x15c0 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x14d0 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x14b0 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x158c R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x11c4 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1610 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1038 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0xd4c R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x728 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x804 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1214 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1614 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1170 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x15bc R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x828 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x804 R at PerformanceCounterLib::get_CategoryTable +0038
I also wrote a simple sample program to demonstrate this problem. I have
included it below. This program creates a PerformanceCounter object and
samples its data for n target servers. When I run it serially, each
individual request takes 2 to 5 seconds (e.g. an average of 3 seconds per
host). When I run it in parallel, it takes approximately the sum of the
serial times (e.g. for 10 hosts that averaged 3 seconds per host serially
will take about 30 seconds in parallel). This strongly suggest some global
lock within the implementation of PerformanceCounter.
I plan to open a support case with MS. If you have any thoughts or
suggestions, they would be appreciated. One more note: our application MUST
simultaneous collect data from multiple targets (so serializing the requests
or eliminating the threading is not an option for us).
using System;
using System.Diagnostics;
using System.Collections;
using System.Threading;
namespace PerfTest
{
class TestPerfCounters
{
[STAThread]
static void Main(string[] args)
{
String[] servers = new String[] {"10.100.1.100", "10.100.1.100",
"10.100.1.101", "10.100.1.102", "10.100.1.103", "10.100.1.104",
"10.100.1.105", "10.100.1.106", "10.100.1.107", "10.100.1.108",
"10.100.1.109", "10.100.1.110", "10.100.1.111", "10.100.1.112",
"10.100.1.113", "10.100.1.114", "10.100.1.115", "10.100.1.116",
"10.100.1.117", "10.100.1.118", "10.100.1.119", "10.100.1.120"};
int size = 10;
// Run the performance counter test for each target serially to demonstrate
estimated times.
TestSerially(servers, size);
// Clean up shared resources so we don't skew our 2nd test
PerformanceCounter.CloseSharedResources();
// Now run performance counter test in parallel, expecting the time to be no
greater than
// the maximum time for a serial run. As you will see, the time is actually
roughly the
// accumulation of the serial times - therefore suggesting an internal
global lock within
// the PerformanceCounter constructor.
TestParallel(servers, size);
}
private static void TestSerially(String[] servers, int size)
{
// Test #1 - Run each serially
Console.WriteLine("*** Start of serial run ***");
DateTime start = DateTime.Now;
for (int i=0; i<size; i++)
{
String server = servers;
WorkerBee tmp = new WorkerBee(i.ToString(), server, "Processor", "%
Processor Time", new String[] {"0"});
tmp.DoIt();
}
DateTime stop = DateTime.Now;
Console.WriteLine("Done in " + (stop - start).TotalMilliseconds);
}
private static void TestParallel(String[] servers, int size)
{
// Test #2 - Run in parallel
Console.WriteLine("*** Start of parallel run ***");
ArrayList workers = new ArrayList();
DateTime start = DateTime.Now;
for (int i=0; i<size; i++)
{
String server = servers;
WorkerBee tmp = new WorkerBee(i.ToString(), server, "Processor", "%
Processor Time", new String[] {"0"});
Thread th = new Thread(new ThreadStart(tmp.DoIt));
th.Start();
workers.Add(th);
}
for (int i=workers.Count-1; i>= 0; i--)
{
Thread th = (Thread)workers;
th.Join();
}
DateTime stop = DateTime.Now;
Console.WriteLine("Done in " + (stop - start).TotalMilliseconds);
}
}
class WorkerBee
{
public String Id;
public String Server;
public String ObjectName;
public String CounterName;
public String[] InstanceNames;
public WorkerBee(String id, String server, String objectName, String
counterName, String[] instanceNames)
{
this.Id = id;
this.Server = server;
this.ObjectName = objectName;
this.CounterName = counterName;
this.InstanceNames = instanceNames;
}
public void DoIt()
{
try
{
DateTime start = DateTime.Now;
Console.WriteLine("Start call for " + Id);
foreach (String instanceName in InstanceNames)
{
PerformanceCounter counter = null;
try
{
DateTime start2 = DateTime.Now;
//Console.WriteLine("Start constructor for " + Id);
counter = new PerformanceCounter(ObjectName, CounterName, instanceName,
Server);
DateTime stop2 = DateTime.Now;
//Console.WriteLine("Stop constructor for " + Id + " to " + Server + " took
" + (stop2 - start2).TotalMilliseconds);
DateTime start3 = DateTime.Now;
counter.NextValue();
counter.NextValue();
DateTime stop3 = DateTime.Now;
//Console.WriteLine("Stop fetch data for " + Id + " to " + Server + " took "
+ (stop3 - start3).TotalMilliseconds);
DateTime stop = DateTime.Now;
Console.WriteLine("Stop call for " + Id + " to " + Server + " took " +
(stop - start).TotalMilliseconds);
}
finally
{
if (counter != null)
counter.Dispose();
}
}
}
catch (Exception ex)
{
Console.WriteLine(ex.Message);
Console.WriteLine(ex.StackTrace);
}
}
}
}
data from a series of servers. These servers are located on different
networks with different speed links. Periodically, one or more of these
links can become very slow. The .Net related problem is that when one link
is slow, it causes all peformance counter collection to other targets - even
those on low latency local networks - to not respond even though they are
running in independent threads.
The data I have collected suggests there is a global lock being used
somewhere in the implementation of PerformanceCounter. From coredbg, I can
see all the threads are simultaneous "stuck"
PerformanceCounterLib:get_CategoryTable. For example, see the below:
Thread 0xd10 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1594 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x15c0 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x14d0 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x14b0 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x158c R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x11c4 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1610 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1038 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0xd4c R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x728 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x804 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1214 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1614 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x1170 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x15bc R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x828 R at PerformanceCounterLib::get_CategoryTable +0038
Thread 0x804 R at PerformanceCounterLib::get_CategoryTable +0038
I also wrote a simple sample program to demonstrate this problem. I have
included it below. This program creates a PerformanceCounter object and
samples its data for n target servers. When I run it serially, each
individual request takes 2 to 5 seconds (e.g. an average of 3 seconds per
host). When I run it in parallel, it takes approximately the sum of the
serial times (e.g. for 10 hosts that averaged 3 seconds per host serially
will take about 30 seconds in parallel). This strongly suggest some global
lock within the implementation of PerformanceCounter.
I plan to open a support case with MS. If you have any thoughts or
suggestions, they would be appreciated. One more note: our application MUST
simultaneous collect data from multiple targets (so serializing the requests
or eliminating the threading is not an option for us).
using System;
using System.Diagnostics;
using System.Collections;
using System.Threading;
namespace PerfTest
{
class TestPerfCounters
{
[STAThread]
static void Main(string[] args)
{
String[] servers = new String[] {"10.100.1.100", "10.100.1.100",
"10.100.1.101", "10.100.1.102", "10.100.1.103", "10.100.1.104",
"10.100.1.105", "10.100.1.106", "10.100.1.107", "10.100.1.108",
"10.100.1.109", "10.100.1.110", "10.100.1.111", "10.100.1.112",
"10.100.1.113", "10.100.1.114", "10.100.1.115", "10.100.1.116",
"10.100.1.117", "10.100.1.118", "10.100.1.119", "10.100.1.120"};
int size = 10;
// Run the performance counter test for each target serially to demonstrate
estimated times.
TestSerially(servers, size);
// Clean up shared resources so we don't skew our 2nd test
PerformanceCounter.CloseSharedResources();
// Now run performance counter test in parallel, expecting the time to be no
greater than
// the maximum time for a serial run. As you will see, the time is actually
roughly the
// accumulation of the serial times - therefore suggesting an internal
global lock within
// the PerformanceCounter constructor.
TestParallel(servers, size);
}
private static void TestSerially(String[] servers, int size)
{
// Test #1 - Run each serially
Console.WriteLine("*** Start of serial run ***");
DateTime start = DateTime.Now;
for (int i=0; i<size; i++)
{
String server = servers;
WorkerBee tmp = new WorkerBee(i.ToString(), server, "Processor", "%
Processor Time", new String[] {"0"});
tmp.DoIt();
}
DateTime stop = DateTime.Now;
Console.WriteLine("Done in " + (stop - start).TotalMilliseconds);
}
private static void TestParallel(String[] servers, int size)
{
// Test #2 - Run in parallel
Console.WriteLine("*** Start of parallel run ***");
ArrayList workers = new ArrayList();
DateTime start = DateTime.Now;
for (int i=0; i<size; i++)
{
String server = servers;
WorkerBee tmp = new WorkerBee(i.ToString(), server, "Processor", "%
Processor Time", new String[] {"0"});
Thread th = new Thread(new ThreadStart(tmp.DoIt));
th.Start();
workers.Add(th);
}
for (int i=workers.Count-1; i>= 0; i--)
{
Thread th = (Thread)workers;
th.Join();
}
DateTime stop = DateTime.Now;
Console.WriteLine("Done in " + (stop - start).TotalMilliseconds);
}
}
class WorkerBee
{
public String Id;
public String Server;
public String ObjectName;
public String CounterName;
public String[] InstanceNames;
public WorkerBee(String id, String server, String objectName, String
counterName, String[] instanceNames)
{
this.Id = id;
this.Server = server;
this.ObjectName = objectName;
this.CounterName = counterName;
this.InstanceNames = instanceNames;
}
public void DoIt()
{
try
{
DateTime start = DateTime.Now;
Console.WriteLine("Start call for " + Id);
foreach (String instanceName in InstanceNames)
{
PerformanceCounter counter = null;
try
{
DateTime start2 = DateTime.Now;
//Console.WriteLine("Start constructor for " + Id);
counter = new PerformanceCounter(ObjectName, CounterName, instanceName,
Server);
DateTime stop2 = DateTime.Now;
//Console.WriteLine("Stop constructor for " + Id + " to " + Server + " took
" + (stop2 - start2).TotalMilliseconds);
DateTime start3 = DateTime.Now;
counter.NextValue();
counter.NextValue();
DateTime stop3 = DateTime.Now;
//Console.WriteLine("Stop fetch data for " + Id + " to " + Server + " took "
+ (stop3 - start3).TotalMilliseconds);
DateTime stop = DateTime.Now;
Console.WriteLine("Stop call for " + Id + " to " + Server + " took " +
(stop - start).TotalMilliseconds);
}
finally
{
if (counter != null)
counter.Dispose();
}
}
}
catch (Exception ex)
{
Console.WriteLine(ex.Message);
Console.WriteLine(ex.StackTrace);
}
}
}
}