SQL Server Performance

[solved?] SQL Profiler: Duration?

Discussion in 'SQL Server 2005 Performance Tuning for DBAs' started by jstryk, Apr 24, 2008.

  1. jstryk New Member

    Hi all!
    At customer's site I encountered a strange issue since yesterday:
    With SQL Profiler I could find lots of statements that have a reasonable amout of Reads/Writes and CPU time, but a remarkably higher Duration. For example, a statement like ...
    SELECT * FROM "navision-wawi"."dbo"."COLER Warenwirtschaft$Sales Line" WHERE (("Document Type"=@P1)) AND (("Document No_"=@P2)) ORDER BY "Document Type","Document No_","Line No_"
    ... takes 5 Reads, 0 Writes, 0 ms CPU but 843 ms Duration! This does apply to multiple different queries, not always, but very often - I could not see any pattern in it.
    First I thought that this indicates a blocking problem, but when searching for blocked processes I couldn't find any ...
    MS SQL Server is 9.0.3042 x64 Enterprise, Client application is MS Dynamics NAV 4.0 25638
    And again: this happens since yesterday, haven't seen this before ...
    Only change - as far as we know - was the installation of the "SQL DBA Dashboard" and "SQL Performance Dashboard", but we couldn't find any real relation between the dashboards and our problem ...
    Any idea what happens here? I appreciate any inspiration - thanks a lot in advance!
    Kind regrads,
    Jörg
  2. jstryk New Member

    maybe this is also important - sp_configure:
    name minimum maximum config_value run_value
    ----------------------------------- ----------- ----------- ------------ -----------
    Ad Hoc Distributed Queries 0 1 0 0
    affinity I/O mask -2147483648 2147483647 0 0
    affinity mask -2147483648 2147483647 0 0
    affinity64 I/O mask -2147483648 2147483647 0 0
    affinity64 mask -2147483648 2147483647 0 0
    Agent XPs 0 1 1 1
    allow updates 0 1 0 0
    awe enabled 0 1 0 0
    blocked process threshold 0 86400 0 0
    c2 audit mode 0 1 0 0
    clr enabled 0 1 0 0
    common criteria compliance enabled 0 1 0 0
    cost threshold for parallelism 0 32767 5 5
    cross db ownership chaining 0 1 0 0
    cursor threshold -1 2147483647 -1 -1
    Database Mail XPs 0 1 1 1
    default full-text language 0 2147483647 1033 1033
    default language 0 9999 0 0
    default trace enabled 0 1 1 1
    disallow results from triggers 0 1 0 0
    fill factor (%) 0 100 0 0
    ft crawl bandwidth (max) 0 32767 100 100
    ft crawl bandwidth (min) 0 32767 0 0
    ft notify bandwidth (max) 0 32767 100 100
    ft notify bandwidth (min) 0 32767 0 0
    index create memory (KB) 704 2147483647 0 0
    in-doubt xact resolution 0 2 0 0
    lightweight pooling 0 1 0 0
    locks 5000 2147483647 0 0
    max degree of parallelism 0 64 2 2
    max full-text crawl range 0 256 4 4
    max server memory (MB) 16 2147483647 2147483647 2147483647
    max text repl size (B) 0 2147483647 65536 65536
    max worker threads 128 32767 0 0
    media retention 0 365 0 0
    min memory per query (KB) 512 2147483647 1024 1024
    min server memory (MB) 0 2147483647 0 0
    nested triggers 0 1 1 1
    network packet size (B) 512 32767 4096 4096
    Ole Automation Procedures 0 1 0 0
    open objects 0 2147483647 0 0
    PH timeout (s) 1 3600 60 60
    precompute rank 0 1 0 0
    priority boost 0 1 0 0
    query governor cost limit 0 2147483647 0 0
    query wait (s) -1 2147483647 -1 -1
    recovery interval (min) 0 32767 0 0
    remote access 0 1 1 1
    remote admin connections 0 1 0 0
    remote login timeout (s) 0 2147483647 20 20
    remote proc trans 0 1 0 0
    remote query timeout (s) 0 2147483647 600 600
    Replication XPs 0 1 0 0
    scan for startup procs 0 1 0 0
    server trigger recursion 0 1 1 1
    set working set size 0 1 0 0
    show advanced options 0 1 1 1
    SMO and DMO XPs 0 1 1 1
    SQL Mail XPs 0 1 0 0
    transform noise words 0 1 0 0
    two digit year cutoff 1753 9999 2049 2049
    user connections 0 32767 0 0
    user options 0 32767 0 0
    Web Assistant Procedures 0 1 0 0
    xp_cmdshell 0 1 1 1
  3. satya Moderator

  4. jstryk New Member

    Thanks a lot for your reply. Well, I doubt that this is related to NAV as I haven't seen this behavior in other systems ...
    I forgot to mention, that this system runs on a Cluster, and our current investigations are directed to this now ...
  5. satya Moderator

    The usual query string you have supplied seems to be user-defined process, such as any constant checkup from ERP:
    SELECT * FROM "navision-wawi"."dbo"."COLER Warenwirtschaft$Sales Line" WHERE (("Document Type"=@P1)) AND (("Document No_"=@P2)) ORDER BY "Document Type","Document No_","Line No_"
    .COLER.... looks like user table within NAV process, so as a test either you can stop the NAV service to see whether the same query is generated from any other user.
  6. jstryk New Member

    Well, this NAV query should be just an example, similar issue happens on various queries on different tables, etc.. On other systems similar queries are processed without the discribed issue ...
    The strange thing which "irritates" me is actually the remarkable difference between the CPU time (0) and the Duration (800) without being blocked. I wonder where the time was spent? What precisely measures "Duration"? Does it include any latencies on the disks or memory?
  7. FrankKalis Moderator

    Have you checked the execution plans to see if they identical under different parameters and to see where the time is spent?
    Is this the complete statement that you've posted, an adhoc query, or a stored procedure? Sounds like you have an IO bottleneck.
  8. jstryk New Member

    Well, I checked the Execution Plans and could not find anything remarkable ... actually they look quite good, regardless if this "time difference" happns or not ...
    NAV is sending RPC to the SQL Server ...
    Could you please specify "I/O Problem"? We can see some "pressure" (high R/W Queues, % Disk Time, etc.) on the disk-subsystem - could this be a reason for this?
  9. FrankKalis Moderator

    Yes, that can be the reason, but it's impossible to judge on this from remote. These might help you: http://sqlblog.com/blogs/andrew_kelly/archive/2008/01/13/getting-back-to-the-basics-with-i-o.aspx
  10. jstryk New Member

    Thanks for your support.
    Strange, yesterday we got a time-window to restart the Cluster and the problem vanished ... I/We have no idea what happens, so I'm curious if the issue will return ... maybe just a system "hickup" ?! ...
    Best regards,
    Jörg

Share This Page