What's a significant LockTimeout measurment in PERFMON?

[Philip Yale]

Recently, using PERFMON, I've been rather dismayed to find that our
application is averaging 3 - 4 lock timeouts per second, and
frequently has extended periods of several minutes where this figure
reaches the hundreds.
Average LockWaits/sec are less than 0.05, and TableLockEscalations/sec
are less than 0.5
These last two seem very good to me, and as a result I would
intuitively expect a LockTimeout figure of near-zero.
Can anyone suggest why the measured LockTimeout value might be so high?
Is the measured value actually considered "high" at all? Doubtless
this depends on a number of things (transaction rate, number of users
etc), but a rule-of-thumb opinion would be welcomed.

[Erland Sommarskog]

Philip Yale (ph********@btopenworld.com) writes:

Recently, using PERFMON, I've been rather dismayed to find that our
application is averaging 3 - 4 lock timeouts per second, and
frequently has extended periods of several minutes where this figure
reaches the hundreds.

Average LockWaits/sec are less than 0.05, and TableLockEscalations/sec
are less than 0.5

These last two seem very good to me, and as a result I would
intuitively expect a LockTimeout figure of near-zero.

Can anyone suggest why the measured LockTimeout value might be so high?
Is the measured value actually considered "high" at all? Doubtless
this depends on a number of things (transaction rate, number of users
etc), but a rule-of-thumb opinion would be welcomed.

Whether this value of lock timeout is high or low depends the lock-
timeout settings. By default, SQL Server does not time out on locks,
but this can be changed with SET LOCK_TIMEOUT. If there some process
which sets the lock timeout to 0, it seems quite normal that you would
get a high lock-timeout rate as 0 means "give up as soon as there is
a lock".

I would use the Profiler and trace the LockTimeout event, to see
where the action is taking place, and then analyse that code to see
if there is a real issue or not.
--
Erland Sommarskog, SQL Server MVP, es****@sommarskog.se

Books Online for SQL Server SP3 at
http://www.microsoft.com/sql/techinf...2000/books.asp

[Phil]

There's only one SP in the entire application suite which specifies a
lock_timeout of 1000 (1 sec), and this is only called at most once
every 2 seconds, so wouldn't itself account for the figures I'm seeing.
Everything else uses the default.

Of course, there's nothing to say that this timeout isn't being set in
the ADO application layer somewhere (I've got the developers looking
into this now).

I set a SQLAgent Alert threshold on SQLServer:Locks:LockTimeouts/sec
to send an email whenever they exceeded a value of 10. Last night, for
a period of 2 hours, I received an alert every minute, with reported
values starting at 12 in the first alert, and rising progressively to
625966 in the last alert !!!!!!!!

The dataserver was rebooted immediately before these alerts started
appearing, and I don't know if that could have caused them (not sure
how, at least not for 2 hours). Over that 2 hour period we also got
raised levvels of lock waits and table lock escalations.

The other alternative is a batch process as the cause, but this didn't
happen the previous night (when all the same batches run), and no
batch that was running over that period failed, as I would have
expected if we were getting so many lock timeouts.

[Erland Sommarskog]

Phil (ph********@btopenworld.com) writes:

I set a SQLAgent Alert threshold on SQLServer:Locks:LockTimeouts/sec
to send an email whenever they exceeded a value of 10. Last night, for
a period of 2 hours, I received an alert every minute, with reported
values starting at 12 in the first alert, and rising progressively to
625966 in the last alert !!!!!!!!

That's a lot!

Did you run Profiler to see what processes that runs into the lock timeouts?


--
Erland Sommarskog, SQL Server MVP, es****@sommarskog.se

Books Online for SQL Server SP3 at
http://www.microsoft.com/sql/techinf...2000/books.asp

[Phil]

Yes, I did.

I think the problem with the Alert setting is that it counts CUMULATIVE
timeouts, and not those occurring at a given sample time. Not terribly
useful.

Regarding the profiler, this is giving me a few pointers to the root
cause, but also raising some new questions. For example, the dbid
column frequently refers to database IDs of 0 and 132. Using SELECT
DB_NAME(), dbid 132 simply doesn't exist, whereas 0 seems to be the
master database, which I always thought was dbid 1 (which it is as
well). Anyone know why master can have 2 database IDs? Anyone know
why profiler reports IDs of 0 and 132, when these databases don't exist?