I/O error every night at 10 pm, why??
in [Server Configuration]
|
Prev: Maintenance Plans in SQL 2005
Next: Help please - Repair fails "There was an error executing the Replication upgrade scripts"
From: tom12010 on 28 Jul 2010 09:08 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 28 Jul 2010 22:34 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 29 Jul 2010 07:17 "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 29 Jul 2010 13:38 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 30 Jul 2010 11:03
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 |