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
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
Welcome to the forum! That might be something to do with that ERP application, so may be search under http://www.microsoft.com/dynamics/community/relatedcommunitieslanding.mspx & http://www.microsoftdynamicsforums.com/forums/forum_topics.asp?FID=7 to see any persistent connection initiated by thsi application, to me it seems its default by design from NAV.
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 ...
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.
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?
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.
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?
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
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