Every night at about 10 pm (2000 hours) on our SQL 2005 since about
7/21 or so we have got this recurring error in our SQL server logs:

07/22/2010 22:00:34,spid2s,Unknown,SQL Server has encountered 1
occurrence(s) of I/O requests taking longer than 15 seconds to
complete on file [D:\LOGS\UNI_MMMMM_Log.ldf] in database [UNI_MMMMM]
(5). The OS file handle is 0x000006C8. The offset of the latest long
I/O is: 0x0000001752dc00

The OS file handle is always the same, the offset is always different.
The spid number is always the same.

This SQL server is the backend for our timekeeping software, and this
event is coincidental with the timekeeping software having nightly
issues at 10 pm.

My research shows this can happen on physical SQL servers with many
disk writes or disk contention, or with insufficient log file space.

Neither of these conditions apply -- the SQL server is a virtual
server on a LUN with very light activity at 1000 pm, the log file
allocation is 2 GB for a 500+ MB database. We did not create the log
file allocation, a consultant did this without telling us that the log
file allocation would be a fixed size, and I have not figured out how
to change the log file. I checked the log file allocation and it
certainly does not appear filled up.

The only event of note since this started is that MS Updates were
performed on the server on 7/19/10 and this issue began on 7/21 after
the VM was migrated to ESX 4.1, which should not have caused any
issues since ESX isn't a database etc.

Any suggestions, ideas, etc. will be very welcome.

Thank you, Tom

Have you checked the SQL Agent for any scheduled jobs that may kick off at
10:00PM? What about on the windows scheduler? There is obviously something
happening on the server at that time and we can tell you what that is but we
can tell u that it is not SQL Server doing anything on it's own.

--

Andrew J. Kelly SQL MVP
Solid Quality Mentors

"tom12010" <tlyczko (AT) gmail (DOT) com> wrote

"tom12010" <tlyczko (AT) gmail (DOT) com> wrote

Check the event logs on the server - look for anything around that time,
such as Volume Shadow Service events, that would indicate maybe a backup
running?

ESX does however control the handling between the server and the hardware,
and anything that can cause the file handling in ESX to slow down will
impact the Windows VM too. Do you have ESX backups running around this time?
VM snapshots being exported? Have you checked the ESX logs for any issues
around 10pm?

I would suspect that ESX is the root cause here.

--
Dan

On Thu, 29 Jul 2010 12:17:21 +0100, "Dan" <news (AT) worldofspack (DOT) com>
wrote:

[snip]

Microsoft Security Essentials is the bugaboo on my XP system.
Yesterday, my system started dragging. It was MSE doing an update.
While I can set when to do a scan, I can not set when to do updates.
Sometimes, it happens when I am busy on my system.

[snip]

Sincerely,

Gene Wirchenko

No backups etc., they are at different times than 10 pm.
No other events in the Event Viewer, I will check the ESX logs to see
what appears.
Thank you, Tom