xp_logininfo running very slow first time it's run in a day

[mrdenny]

I've got a strange problem that I can't seam to find anything on the net about.

Server is Windows 2000 Standard
SQL is SQL 2000 Standard SP3 (8.00.760)

We have a stored procedure that uses xp_logininfo. Every morning the first time the procedure is run xp_logininfo takes about 39 seconds to run. Every time after that it takes less than a second to run and get back the data.

Has anyone seen something like this before?

We are only seeing this on the QA server. We think that we would be having this problem in production except that people are using the production system 24x7 so we don't think the system has a change to "time out" the connection to the domain like the QA server does.

The stranger part is that if we reboot the SQL Server the problem does not show up until the next morning.

I've broken apart the procedure and have verified that it's xp_logininfo specifically that is running slow. I'm open to any ideas that anyone has as long as they make sense.

Unfornitually it's a large database so it can't be moved to another QA server. Other servers on the network do not seam to have this issue.

Denny
MCSA (2003) / MCDBA (SQL 2000)

--Anything is possible. All it takes is a little research. (Me)

http://www.mrdenny.com

(Not quite so old any more.)

 

[Catadmin]

Denny,

Do you have SP 4 on your box? Here's a Microsoft KB article I found regarding some strange things with that particular Proc. It may be affecting the way you see the proc act inside your other proc.

http://support.microsoft.com/?kbid=838460

My other thought is to wonder if xp_logininfo is stored With Recompile on it. I can't find my copy of that proc under the Master database to verify this thought, though.



Catadmin - MCDBA, MCSA
"If a person is Microsoft Certified, does that mean that Microsoft pays the bills for the funny white jackets that tie in the back???

 

[mrdenny]

xp_logininfo is not storred with recompile on it. It's a system stored procedure. We are service pack 3 (Build 760). The problem in kb 838460 effects servers with build 840 and above. I checked that out already.

Denny
MCSA (2003) / MCDBA (SQL 2000)

--Anything is possible. All it takes is a little research. (Me)

http://www.mrdenny.com

(Not quite so old any more.)

 

[Catadmin]

Ah. Sorry, didn't mean to repeat work you had already done.

I haven't run into that problem myself, but let me ask around and see if anyone else has experienced problems with it.



Catadmin - MCDBA, MCSA
"If a person is Microsoft Certified, does that mean that Microsoft pays the bills for the funny white jackets that tie in the back???

 

[mrdenny]

Cool, thanks.

Denny
MCSA (2003) / MCDBA (SQL 2000)

--Anything is possible. All it takes is a little research. (Me)

http://www.mrdenny.com

(Not quite so old any more.)

 

[Catadmin]

Denny,

Not everyone has responded to me yet, but consensus seems to be that xp_loginInfo is somehow recompiling itself on a daily basis. We don't know why, though.

I'll let you know if I find out anything else.



Catadmin - MCDBA, MCSA
"If a person is Microsoft Certified, does that mean that Microsoft pays the bills for the funny white jackets that tie in the back???

 

[Catadmin]

Denny,

What's your Proc's name? Does it start with sp_ ?

Brian Knight (yes, I work down the hall from the president of PASS @=).) says you might be getting a cache miss if it is named like that. So, you might try renaming your proc (at least remove the underscore?) and see if that helps.



Catadmin - MCDBA, MCSA
"If a person is Microsoft Certified, does that mean that Microsoft pays the bills for the funny white jackets that tie in the back???

 

[mrdenny]

I've taken the code out of the stored procedure and manualy set the input variable and I'm running it directly through query analyzer.

I've added some additional time stamping comments to the stored procedure, and apparently it's not actually the xp_logininfo procedure that's causing the error.

Here's how I know it's the delete statement.

delete old - 09:46:59
Done with delete - 09:47:39

This statement is what's causing the problem with the print statements.

print 'delete old - ' + convert(varchar(10), getdate(), 108)
delete l_User_Groups
where Account_Name = @thisuser
print 'Done with delete - ' + convert(varchar(10), getdate(), 108)

This table has a whopping 1227 records in it.
The Account_Name column has a clustered index on it.

The strange thing is that the server trace through QA shows the following.

Text Event Class Duration CPU Reads Writes
delete l_User_Groups where Account_Name = @thisuser SQL:StmtCompleted 39 0 22 4

Scan Density is 100%.
Logical Scan Fragmentation is 0.00%
Extent Scan Fragmentation is 50%.

DBCC SHOWCONTIG scanning 'l_User_Groups' table...
Table: 'l_User_Groups' (620789519); index ID: 1, database ID: 7
TABLE level scan performed.
- Pages Scanned................................: 27
- Extents Scanned..............................: 4
- Extent Switches..............................: 3
- Avg. Pages per Extent........................: 6.8
- Scan Density [Best Count:Actual Count].......: 100.00% [4:4]
- Logical Scan Fragmentation ..................: 0.00%
- Extent Scan Fragmentation ...................: 50.00%
- Avg. Bytes Free per Page.....................: 4044.9
- Avg. Page Density (full).....................: 50.03%
DBCC execution completed. If DBCC printed error messages, contact your system administrator.

Image of the part of this part of the actual query plan.

http://www.mrdenny.com/tek/QueryPlan.jpg

Row Count: 2
IO Cost: 0.0101
Disk Cost: 0.000004
Cost: 0.016565

Any ideas?

Denny
MCSA (2003) / MCDBA (SQL 2000)

--Anything is possible. All it takes is a little research. (Me)

http://www.mrdenny.com

(Not quite so old any more.)

 

[Catadmin]

Denny,

Is that a clustered index Scan or a Seek? What is your input parameter - AccountName?




Catadmin - MCDBA, MCSA
"If a person is Microsoft Certified, does that mean that Microsoft pays the bills for the funny white jackets that tie in the back???

 

[mrdenny]

The input paramater is "@thisuser". It's entered as the full domain account name for the user.

It's a Clustered Index Delete.

I've updated the pic on my site with the popup info from the execution plan.

Denny
MCSA (2003) / MCDBA (SQL 2000)

--Anything is possible. All it takes is a little research. (Me)

http://www.mrdenny.com

(Not quite so old any more.)