2009-11-11 61 views
3

对于我的生活,我无法弄清楚我的代码中的这种性能。我有,我测量它需要多长时间运行构造的容器对象(对象下方),在公共构造计时码现在C#创建对象比构造函数调用慢得多

public class WorkUnit : IWorkUnit 
{ 
    private JobInformation m_JobInfo; 
    private MetaInfo m_MetaInfo; 
    private IPreProcJobInfo m_PreprocDetails; 


    readonly private Guid m_ID; 
    private Guid m_ParentID; 
    private Guid m_MasterJobID; 


    private string m_ErrorLog = string.Empty; 
    private PriorityKeeper m_Priority; 
    private WorkUnitClassification m_Classification; 

    private IJobPayload m_CachedPayload; 
    private IJobLogger m_Logger; 
    private EventHandler<JobEventArgs> m_IsFinished; 
    private ReaderWriterLockSlim m_Lock; 

    public WorkUnit(string InputXML, Guid JobID, IJobLogger Logger) 
    { 
     DateTime overstarttime = DateTime.Now; 

     try 
     { 
     ....Do Stuff.... 
     } 
     catch(XMLException e) 
     {...} 
     catch(Exception e) 
     { 
     ... 
     throw; 
     } 

     double time = (DateTime.Now - overstarttime).TotalMilliseconds 
     Console.WriteLine("{0}", time); 
    } 

    /// <summary> 
    /// Private Constructor used to create children 
    /// </summary> 
    private WorkUnit(Guid MasterID, Guid ParentID, WorkUnitClassification Classification, PriorityKeeper Keeper) 
    {...} 

    [OnDeserializing()] 
    private void OnDeserialize(StreamingContext s) 
    {...} 

    public PriorityKeeper PriorityKey 
    {...} 

    public bool HasError 
    {...} 

    public bool Processing 
    {...} 

    public bool Splittable 
    {...} 

    public IEnumerable<IWorkUnit> Split(int RequestedPieces, int Bonds) 
    {...} 

    public void Merge(IResponse finishedjob) 
    {...} 

    public ReadOnlyCollection<IWorkUnit> Children 
    {...} 

    public bool IsMasterJob 
    {...} 

    public Guid MasterJobID 
    {...} 

    public Guid ID 
    {...} 

    public Guid ParentID 
    {...} 

    public EnumPriority Priority 
    {...} 

    public void ChangePriority(EnumPriority priority) 
    {...} 

    public string ErrorLog 
    {...} 

    public IMetaInfo MetaData 
    {...} 

    public IJobPayload GetProcessingInfo() 
    {... } 

    public IResponseGenerator GetResponseGenerator() 
    {... } 

} 

,我测量它需要创建对象的总时间

DateTime starttime = DateTime.Now; 
var test = new WorkUnit(temp, JobID, m_JobLogger); 
double finished = (DateTime.Now - starttime).TotalMilliseconds; 

,我一直得到以下性能数字 -

构造的时间 - 47毫秒

对象的创建时间 - 387毫秒

47 ms是可以接受的,387真的很差。取出日志会忽略改变这些数字。有谁知道为什么这么长时间?我的系统是VS 2008 SP1,面向Windows XP上的.NET 3.5 SP1。我将不胜感激任何解释。我很快就会分析这个剖析器,但我觉得它无法深入到我需要解释这种行为的层面。谢谢你的帮助。

编辑:我在发布运行

+0

如果没有'try'和'catch'代码中的代码,就很难猜测。也许你可以发布更多的代码?是否抛出异常(斯诺克)? – 2009-11-11 18:14:37

+2

您是在测量第一次调用特定代码路径还是平均调用SUBSEQUENT?请记住,对任何事物的第一次调用可能会更加昂贵,因为它需要加载它所引用的所有DLL的传递闭包,在它使用的类型的静态构造函数中运行所有代码,然后jit编译所有不是代码的代码。首次下载代码路径通常比每个后续的调用都要昂贵得多。 – 2009-11-11 18:20:04

回答

7

您确定您所看到的是对象创建时间,而不是CLR启动的影响吗?

尝试在循环中运行测试50次并忽略第一个结果。

+0

就是这样,第一次真的很慢,在这之后快得多 – Steve 2009-11-11 18:20:54

+1

只是我的两分钱:我认为这里真正的罪魁祸首是'DateTime.Now',它在第一次运行时比之后的所有时间都要慢。 (我知道,我已经介绍过它。)既然你在构造函数之前调用它,*那*是缓慢的;那么在你的构造函数和后来的两个应该很快。 – 2009-11-11 18:44:09

+2

这是有道理的。 DateTime.Now需要做各种有趣的事情,比如说我现在是夏令时,我在哪个时区等等。第一次加载所有的代码是昂贵的;随后每个时间都很便宜,因为它只是调用“热门”代码,而不是加载它“冷”。 – 2009-11-11 19:57:07

2

时间带出Red Gate Performance Profiler。而不是要求我们猜测问题可能是什么......下载试用版,并让它告诉你究竟你的问题在哪里。

轮廓仪是很好的工具。任何开发人员都应该熟悉如何利用它们来查明性能问题。

0

你知道吗Console.WriteLine在构造函数中抛出你的时机巨大?任何IO操作都会抛弃这些时序。

如果你想要真正的数字,把持续时间存储在一个全球的某个地方然后打印出来你已经记录了一切。

+0

如果我发表评论,我仍然可以大致同时构建对象 – Steve 2009-11-11 18:13:52

6

史蒂夫,

这里有几件事情要考虑:使用日期时间来使用StopWatch

  1. 开关。对于这些类型的情况来说更准确。
  2. 停止在计时过程中写入控制台。 IO将会很重要,并影响你的时间安排。
  3. 确保您在发布/优化版本中运行,并且不在Visual Studio测试主机下运行。如果你从一个默认VS运行,切换到Release,编译并使用Ctrl + F5(而不是F5)来运行。

鉴于您的时机,我猜#2是你的问题。 Visual Studio增加了大量影响性能的“钩子”。在Visual Studio中运行时的时间。

+0

不幸的是,我在发布中运行 – Steve 2009-11-11 18:13:12

+0

您是否在Visual Studio中运行?只需切换到释放是不够的 - 确保不要在测试主机内部运行。 – 2009-11-11 18:14:09

+0

这听起来像是你遇到了这样一个事实,即测试主机需要挂钩到每个对象中,这会增加很大的开销。 – 2009-11-11 18:14:46

4

首先使用StopWatch类来测量时间。系统时间的分辨率太低,无法给出准确的结果。

尝试创建该类的多个实例。程序集第一次可能不是JIT:ed,这当然需要一些时间。

1

该问题包含自己的答案;除了运行构造函数之外,还有更多的实例化对象。当你调用new时,你要求运行时为对象分配空间,处理运行时需要的任何内部簿记,为每个基类型调用构造函数(在本例中,仅为object),最后调用构造函数。

当你测量总实例化时间时,你正在测量所有这些;当你单独计算构造函数时,你只能测量一部分。如果数字不是不同,那会引起担忧。

1

正如其他人建议,首先,绝对开关使用System.Diagnostics.Stopwatch:

public WorkUnit(string InputXML, Guid JobID, IJobLogger Logger, out TimeSpan elapsed) 
{ 
    Stopwatch constructionStopwatch = Stopwatch.StartNew(); 

    // constructor logic 

    constructionStopwatch.Stop(); 
    elapsed = constructionStopwatch.Elapsed; 
} 

然后:

TimeSpan constructionTime = TimeSpan.Zero; 
Stopwatch creationStopwatch = Stopwatch.StartNew(); 

var test = new WorkUnit(temp, JobID, m_JobLogger, out constructionTime); 

creationStopwatch.Stop(); 
TimeSpan creationTime = creationStopwatch.Elapsed; 

double constructionMs = constructionTime.TotalMilliseconds; 
double creationMs = creationTime.TotalMilliseconds; 

的原因我建议切换到使用TimeSpan对象,而不是像(DateTime.Now - startTime).TotalMilliseconds这样的东西是,虽然它应该没有什么区别,但在技术上,在后一种情况下,你首先要求获得时间和然后得到TotalMilliseconds属性,我几乎可以肯定是一个计算值,在构造函数中。这意味着在之间实际上有一个步骤检查构造函数中的时间,并在之后立即检查时间。真的,这应该基本上可以忽略不计,但覆盖所有基地是很好的。

相关问题