3
\$\begingroup\$

I'll try to keep this as short as I can without losing context - we have a system for online education, where presentations often have a test.

Management has access to a report used for measuring compliance. The report has a few paramaters that need to be selected:

  • A date range to look in (e.g. From 11 March 2010 to 11 March 2011)
  • One or more online tests (it's a hospital, so some topics have a clinical and a non-clinical version)
  • One or more departments (so VPs can see all their departments, managers can see just their department, etc.)
  • There are a couple of options for filtering the results (showing all results, showing only "missing" results - kinda broken at this point, excluding "missing" results)
  • The report can be pulled as an Excel spreadsheet or as a web page (The Excel option is going to go away due to some issues with Excel 2007, I just haven't had time to remove it)

2011-03-17 Addendum:

As per munificent's advice (and apparently an earlier me's notes) I used http://aspprofiler.sourceforge.net/ to get a little more hard data.

Getting the data from SQL Server Express 2005 (which is running on the same machine) seems to be the biggest culprit.

Set objResultsRS = objSQLDB.Execute(,,adCmdText) has taken anywhere from 33% to 50% of the processing time.

If Not objResultsRS.BOF Then objResultsRS.MoveFirst takes another 20% - 26% of the time - I'll be damned if I can figure out why its even running... since the data is getting dumped into an array, I probably don't need to check BOF and EOF to see if I've got an empty recordset - I just need to check if the array is empty. I'll test to see if that yields any improvements worth reporting.

Nothing else is taking more than 3% of the processing time. I've run a fairly typical report checking system-wide compliance with two online test from 11 March 2010 to 11 March 2011. (a report that is being run constantly this month by just about every VP, and the source of half the support calls I've been taking.)

The SQL for that run ends up looking like:

SELECT LEmp.LawsonID, LEmp.LastName, LEmp.FirstName, LEmp.MidInit, LEmp.winUserName, LPos.Position, LEmp.AccCode, LDept.DisplayName, LEmp.EmpStatus, 
    Log.VerificationID, Log.WinLogon, Log.Name, Log.Position, Log.Pass, Log.DoneTime, Log.Title 
FROM ((Lawson_Employees AS LEmp LEFT JOIN Lawson_DeptInfo AS LDept ON LEmp.AccCode = LDept.AccCode) 
    INNER JOIN Lawson_PositionCodes AS LPos ON LEmp.PosCode = LPos.PosCode) 
    LEFT JOIN (
            SELECT V.VerificationID, V.WinLogon, V.LawsonID, V.Name, V.Position, V.Pass, V.DoneTime, C.Title 
            FROM Testing_TestLogs AS V LEFT JOIN Testing_Content AS C ON V.PresID = C.PresID 
            WHERE V.PresID IN (284,285) 
            AND V.DoneTime >= '20100311000000' AND V.DoneTime <= '20110311235959' AND V.Name <> 'program check'
        ) AS Log ON LEmp.LawsonID = Log.LawsonID 
WHERE LEmp.CurrentEmp = 1 AND LEmp.AccCode <> '106000' 
AND LEmp.EmpStatus NOT IN ('CT','EN','R1','R2','T1','T2','T3') 
ORDER BY LEmp.AccCode ASC, LEmp.LastName ASC, LEmp.FirstName ASC, Log.DoneTime ASC;

2011-03-23 Addendum:

As much as I'd like to devote more time to this PITA, I've got other deadlines pressing in. The sub-query seems to be what is causing the most grief from the SQL Server end (thanks Mongus), but I ran out of time to devote too much attention to it.

By duming whatever was returned into the array anyway, and then checking if the array was empty, I was able to get a ~20% improvement. So that section now looks like this:

Dim objSQLDB : Set objSQLDB = CreateObject("ADODB.Command")

objSQLDB.ActiveConnection = strTestingConn
objSQLDB.CommandText = strSQL

Set objResultsRS = objSQLDB.Execute(,,adCmdText)
arrResults = objResultsRS.GetRows(adGetRowsRest)
intTotResults = UBound(arrResults,2)

objResultsRS.Close
Set objResultsRS = Nothing
Set objSQLDB = Nothing

If Not IsArray(arrResults) Then
    'No results, show the page then end the script'         

objResultsRS.Close
    Set objResultsRS = Nothing
    Set objSQLDB = Nothing
    Response.End()
End If

I'm leaving the (somewhat snipped) code at the bottom for reference/context.

%><!-- #include virtual="/educationtesting/inc_testingstuff.asp" --><%
'--> Removed some variable declarations that are used by the library below, but not in the main code below <--'
%><!-- #include virtual="/forum/inc_func_common.asp"--><% 

'--> Removed declarations and validation of incoming data <--'

strSQL = "SELECT LEmp.LawsonID, LEmp.LastName, LEmp.FirstName, LEmp.MidInit, LEmp.winUserName, LPos.Position, LEmp.AccCode, LDept.DisplayName, LEmp.EmpStatus, "
strSQL = strSQL & "Log.VerificationID, Log.WinLogon, Log.Name, Log.Position, Log.Pass, Log.DoneTime, Log.Title "
strSQL = strSQL & "FROM ((Lawson_Employees AS LEmp LEFT JOIN Lawson_DeptInfo AS LDept ON LEmp.AccCode = LDept.AccCode) "
strSQL = strSQL & "INNER JOIN Lawson_PositionCodes AS LPos ON LEmp.PosCode = LPos.PosCode) "
strSQL = strSQL & "LEFT JOIN "
strSQL = strSQL & "(SELECT V.VerificationID, V.WinLogon, V.LawsonID, V.Name, V.Position, V.Pass, V.DoneTime, C.Title "
strSQL = strSQL & "FROM Testing_TestLogs AS V LEFT JOIN Testing_Content AS C ON V.PresID = C.PresID "
strSQL = strSQL & "WHERE V.PresID IN (" & intPresID & ") "
strSQL = strSQL & "AND V.DoneTime >= '" & strFrom & "' AND V.DoneTime <= '" & strTo & "' "
strSQL = strSQL & "AND V.Name <> 'program check') "
strSQL = strSQL & "AS Log ON LEmp.LawsonID = Log.LawsonID "
strSQL = strSQL & "WHERE LEmp.CurrentEmp = 1 "
Select Case LCase(strAccCode)
    Case "all"
    Case "mgmt"
        strSQL = strSQL & "AND (LDept.VP = '" & Session(strCookieURL & "strWinFullName") & "' "
        strSQL = strSQL & "OR LDept.SLD = '" & Session(strCookieURL & "strWinFullName") & "' "
        strSQL = strSQL & "OR LDept.DeptMgr = '" & Session(strCookieURL & "strWinFullName") & "') "
    Case Else
        strSQL = strSQL & "AND LEmp.AccCode IN (" & strAccCode & ") "
End Select

'Filter out the suspense account'
strSQL = strSQL & "AND LEmp.AccCode <> '106000' "

'Filter out LOA, FMLA, etc.'
strSQL = strSQL & "AND LEmp.EmpStatus NOT IN ('CT','EN','R1','R2','T1','T2','T3') "

Dim strRptHead : strRptHead = ""
Select Case UCase(Trim(Request.Form("Filter")))
    Case "C"
        strSQL = strSQL & "AND Log.VerificationID IS NOT NULL "
        strSQL = strSQL & "ORDER BY LEmp.AccCode ASC, LEmp.LastName ASC, LEmp.FirstName ASC, Log.DoneTime ASC;"
        strRptHead = "Only completed records"
    Case "NC"
        strSQL = strSQL & "AND Log.VerificationID IS NULL "
        strSQL = strSQL & "ORDER BY LEmp.AccCode ASC, LEmp.LastName ASC, LEmp.FirstName ASC;"

        strRptHead = "All missing records"
    Case Else
        strSQL = strSQL & "ORDER BY LEmp.AccCode ASC, LEmp.LastName ASC, LEmp.FirstName ASC, Log.DoneTime ASC;"
        strRptHead = "All compliance results"
End Select

Dim objResultsRS, arrResults, intTotResults
Dim objSQLDB : Set objSQLDB = CreateObject("ADODB.Command")
objSQLDB.ActiveConnection = strTestingConn
objSQLDB.CommandText = strSQL
Set objResultsRS = objSQLDB.Execute(,,adCmdText)

If Not objResultsRS.BOF Then objResultsRS.MoveFirst
If objResultsRS.EOF Then
    'No results, show the page then end the script'
    '--> Snipped code that showed message re: no records, and what may be at issue <--'
    objResultsRS.Close
    Set objResultsRS = Nothing
    Set objSQLDB = Nothing
    Response.End()
Else
    'Results, drop the recordset into an array and close out the DB connection'
    arrResults = objResultsRS.GetRows(adGetRowsRest)
    intTotResults = UBound(arrResults,2)
    objResultsRS.Close
    Set objResultsRS = Nothing
    Set objSQLDB = Nothing
End If

'send mime type et al for headings'
Select Case strDisplay
    Case "page"
        '--> Snipped code to write out HTML header info <--'
    Case "excel"
        'Returns the result as an Excel spread sheet.'
        Response.ContentType = "application/vnd.ms-excel"
        Response.AddHeader "content-disposition","attachment;filename=AllResults_" & strFrom & "_To_" & strTo & ".xls"
        '--> Snipped code to write out Excel header info <--'
    Case Else
        Response.Redirect("oops.asp?Err=BadDisplay")
End Select

Select Case strDisplay
    Case "page"
        Response.Write("<table class=""fcc iffc c tc tbc"" cellspacing=""0"" style=""font-size:8pt;"">" & vbNewLine)
        If LCase(strAccCode) = "mgmt" Then
            '--> Show a note to managers re: what to do if a department is/not on the list that should/not be there <--'
        End If
        '--> Write out the main report header, formatted for a web page <--'
        strExcelExtra = ""
    Case "excel"
        '--> Write out the main report header, formatted for an Excel sheet <--'
        strExcelExtra = " style=""mso-number-format:\@;"""
    Case Else
        Response.Redirect("oops.asp?Err=BadDisplay")
End Select

'--> Removed some declarations for variables used below <--'

'Write out each row of data'

'--> Removed the horridly long chunk of code for writing out each row - profiler showed it was not that big of a time suck <--'

'Done, close up table'
Response.Write("</table>" & vbNewLine)
If strDisplay = "page" Then Response.Write("<h3 class=""c""><a href=""#"" onClick=""window.close()"">Close this window</a></h3>" & vbNewLine & "</center>" & vbNewLine)
Response.Write("</body>" & vbNewLine & "</html>")
%>

Footnote: Don't think it will matter, but I will be stripping out the Excel support sometime in the near future. As a dev team of 1 (and server admin, db admin, designer, tester, maintainer, etc.), there are a couple other projects that need to get finished before I can do that.

\$\endgroup\$
  • 1
    \$\begingroup\$ Yeesh! Is it Set objResultsRS = objSQLDB.Execute(,,adCmdText) that's taking so long? If so then capture the SQL before executing. People will find that a lot easier to analyse. \$\endgroup\$ – pdr Mar 15 '11 at 23:23
  • \$\begingroup\$ @pdr: not as far as I've been able to tell - it's certainly worth re-visiting. \$\endgroup\$ – AnonJr Mar 16 '11 at 0:31
  • 1
    \$\begingroup\$ You really must do some basic profiling to narrow down where the time is taken. Certainly building the SQL query takes almost no time compared to running it. Processing the results (I didn't read that far) may take a significant amount of time, or not. But you should add some simple timing around the major sections to find out. Then you can ask a more useful question that will lead you to an answer. \$\endgroup\$ – David Harkness Mar 16 '11 at 2:06
  • \$\begingroup\$ @David - as a sanity-check, which points would you reccomend using as reference points? \$\endgroup\$ – AnonJr Mar 16 '11 at 20:49
  • \$\begingroup\$ @AnonJr - At least time the query since that's probably the culprit. And of course time the whole thing. If you find the query takes 90% of the time, that's where you need to drill down. I'm sure the query you end up building is rather complex, and the only way to see what's happening is to use your database's explain feature which tells you how it will execute the query: what indexes it uses, how many rows it gets along the way, if it does any table scans, etc. \$\endgroup\$ – David Harkness Mar 17 '11 at 0:11
6
\$\begingroup\$

It makes me sad how few people seem to know this basic advice: If you have a program that's slow profile it. It takes five minutes to download a trial of a profiler, hook it up to your app, and see exactly where the bottlenecks are. Computers are much too complicated to reason about performance from first principles anymore.

As long as you have the right algorithm (which you do need to reason about before you get this far) you'll make progress much faster with a profiler than you will just trying to guess at stuff. Almost every time I've had a performance problem, a profiler has revealed it wasn't at all where I thought it was.

\$\endgroup\$
  • \$\begingroup\$ Try googling "profiler <your language>" and see what turns up. I'm not that familiar with SQL so I don't know if there's any mistakes there. \$\endgroup\$ – munificent Mar 16 '11 at 23:34
  • \$\begingroup\$ Damnedest thing... I had to increase the buffer size to be able to get full results from the profiler, and now I'm getting different (slightly better) results on the basic stats. \$\endgroup\$ – AnonJr Mar 17 '11 at 20:37
  • \$\begingroup\$ Cleaning up my earlier comments, and added some information from the profiler - that I'd used 2 years ago and forgotten that I had... \$\endgroup\$ – AnonJr Mar 17 '11 at 20:56
  • \$\begingroup\$ It's not as optimal as I'd like, but it's as optimal as I have time to make it. Thanks for the profiling reminder. \$\endgroup\$ – AnonJr Mar 23 '11 at 23:26
4
\$\begingroup\$

How large is the data that you are pulling in?

If the Testing_TestLogs table is massive (the name makes me think it might be), have you got indexes on the LawsonID column?

If Testing_Content is massive - have you got an index on the PresID column?

As both of these tables get pulled in to the query the database is having to sort the data by these columns. The more data, the slower this operation will be.

I would recommend getting the exeuction plan of this query to see which joins are the slowest. The right index in the right place makes a massive difference!

\$\endgroup\$
  • \$\begingroup\$ It is massive, and there are indexes on the ID columns. I've tried to get some execution plans, but I'm not sure I'm running them right... my SQL Server knowledge comes more "trial by fire" than "excellence in education" \$\endgroup\$ – AnonJr Mar 16 '11 at 18:36
  • \$\begingroup\$ In Management Studio select Query -> Include Actual Execution Plan. Then run your query. You will get an Execution Plan tab next to your results. This will be massive, but well worth going over. It shows all the operations that SQL Server had to do together with the Cost. Find the items with the highest cost. \$\endgroup\$ – Mongus Pong Mar 17 '11 at 9:29
  • \$\begingroup\$ "Clustered Index Scan Testing_TestLogs" seems to cost 92%; Seems to be related to the sub-query. \$\endgroup\$ – AnonJr Mar 18 '11 at 21:00
2
\$\begingroup\$

Since others have answered re: make sure you have proper indexes (any FK'd column and any column you are filtering/selecting on pretty much), and to check you execution plan - I can see a couple of problems.

Just a cursory glance through the proc - I can see there are a large number of non-sargable statements. This prevents effective use of your indexes and will slow the query down considerably on large datasets.

For times, you should use the built in "BETWEEN" keyword.

http://www.dotnet4all.com/snippets/factsheet%20SQL%20Server.pdf

Look at the sargability, and checklist for indexes on the above link. It is a great quick-resource.

Also since you made a note of it, you need to check for BOF or EOF otherwise you'll get a 500 when you attempt to access the recordset [if it is empty].

\$\endgroup\$
  • \$\begingroup\$ My thought on the BOF/EOF was more along the lines of "since I'm dumping it into an array anyway, it may be faster to check if arrResults is an array or not". I've not had a chance to do some a/b testing yet. ("other job duties" and all) \$\endgroup\$ – AnonJr Mar 21 '11 at 21:54
  • \$\begingroup\$ Using BETWEEN has made no difference one way or the other, but dumping the recordset to an array and then checking to see if the array is empty sped things up by ~20%... go figure. \$\endgroup\$ – AnonJr Mar 22 '11 at 17:44

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.