From: tom12010 on
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
From: Andrew J. Kelly on
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(a)gmail.com> wrote in message
news:78ebb92b-0f52-4168-a54a-b30ae272e18c(a)c10g2000yqi.googlegroups.com...
> 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

From: Dan on

"tom12010" <tlyczko(a)gmail.com> wrote in message
news:78ebb92b-0f52-4168-a54a-b30ae272e18c(a)c10g2000yqi.googlegroups.com...
> 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.

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?

> 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.

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

From: Gene Wirchenko on
On Thu, 29 Jul 2010 12:17:21 +0100, "Dan" <news(a)worldofspack.com>
wrote:

[snip]

>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?

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
From: tom12010 on
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