How to solve ESE -566 Errors (JET_errDbTimeTooOld)

Hello all,

After having this issue at a customer, and finding the information on the internet to be a bit old (and haste) I wanted to post what occurred and how to solve it.

So over the weekend I had DR testing at a customer. They are running Exchange 2007 SP3RU8 on all servers, and for HA they have a two node Single Copy Cluster.

We did some maintenance on the cluster, and then attempted to fail over. After waiting about 3 minutes I decided to check (as a healthy cluster should fail over within 60-90 seconds). Afterwards, I saw three DB that refused to mount.

I reviewed the Event Viewer: System logs and saw this..

Event Type: Warning
Event Source: PartMgr
Event Category: None
Event ID: 59
Date:
Time:
User:
Computer: SCC-Node2
Description:
Disk 75 will not be used because it is a redundant path for disk 0.

Not really a warm fuzzy feeling, so I decided to fail back over to SCC-Node1. When that occurred I attempted to mount both of the databases that refused to mount (within Cluster Admin utility by bringing the IS Instance online) and failed. Once I looked within the Event Viewer: Application logs I saw a slew of these error messages:

Event Type: Error
Event Source: ESE
Event Category: Logging/Recovery
Event ID: 516
Date:
Time:
User: N/A
Computer: SCC-Node1
Description:
MSExchangeIS (6312) StorageGroup1: Database F:\database1\database1.edb: Page 231 (0x000000e7) failed verification due to a timestamp mismatch. The expected timestamp was 0xbedab929 but the actual timestamp on the page was 0xbedab403. Recovery/restore will fail with error -566. If this condition persists then please restore the database from a previous backup. This problem is likely due to faulty hardware “losing” one or more flushes on this page sometime in the past. Please contact your hardware vendor for further assistance diagnosing the problem.

and then a few of these:

Event Type: Error
Event Source: ESE
Event Category: Logging/Recovery
Event ID: 454
Date:
Time:
User: N/A
Computer: SCC-Node1
Description:
MSExchangeIS (4408) StorageGroup1: Database recovery/restore failed with unexpected error -566.

The first thing I checked was the health of the actual DB. To do this you should run the following:

  1. Open the Command Prompt
  2. Change directory to %programfiles%\Microsoft\Exchange Server\Bin
  3. Run the ESEUTIL command (eseutil /mh <DriveLetter>:\Path_To_DB)

This command dumps the DB headers, and will give you two pieces of critical information you are looking for:

  • State
  • Log Required

Here is the output from the command I ran:

Initiating FILE DUMP mode…
Database: D:\Database1\Database1.edb

File Type: Database
Format ulMagic: 0x89abcdef
Engine ulMagic: 0x89abcdef
Format ulVersion: 0×620,12
Engine ulVersion: 0×620,12
Created ulVersion: 0×620,12
DB Signature: Create time:09/15/2010 16:58:36 Rand:2592704934 Computer:
cbDbPage: 8192
dbtime: 3888704209 (0xe7c8ead1)
State: Dirty Shutdown
Log Required: 1829641-1829643 (0x1beb09-0x1beb0b)

At this point, I know I am going to need to do some type of recovery that is going to require the logs in the “Log Required” section.

Before I continue, lets discuss what actually happened here based off what I see from my troubleshooting..

What would cause this: 

Before fully understanding why this occurred  you should understand how dbTime works and how the Information Store works. There is a good article here about the Information Store process, but to sum it up there is a Log Buffer that is within the memory. To help reduce I/O on your disk subsystem, transactions are written to the Log Buffer. The Log Buffer (being 1MB in size, since transaction logs are that size) then commits to a log when one of two things happen:

  1. The DB is failing over, and needs to commit the transaction to memory. This could be due to node failure, turning the server off or HA testing
  2. A hard transaction hits the DB (send / receive of email, ect)

When the log buffer needs to write, it writes using the Log Writer process.

To summarize, transactions are not written to the DB immediately but instead to the log buffer and then from the log buffer written from the log buffer utilizing the log writer to the DB.

As for the dbTime, when a new log is generated a unique database time is generated based off the log generation time. The dbTime can be higher than the actual current log time, which is normal. The dbTime is utilized more as a counter than an actual time stamp.

Why does this occur? When we perform DR (hard / soft recoveries) on a DB, the dbTime is examined to see if the log has been replayed or not.

Now to the actual root cause..

What it looked like was that when SCC-Node1 failed over to SCC-Node2, the disk subsystem was overwhelmed along with the network backbone for the SAN, thus causing a mismatch in the time. If you look at Error -566 utilizing the Exchange Error Tool you would see that this theory does match up to the actual error:

JET_errDbTimeTooOld esent98.h
# /* dbtime on page smaller than dbtimeBefore in record */

The question now is how to fix it..

The Fix: 

Although the article above states you should run “ESEUTIL /P” I highly disagree with this. ESEUTIL /P should be ran only as a last resort. I was able to fix this quite quickly using ESEUTIL /R.

From our ESEUTIL /MH content above we know the DB is in a dirty shutdown state, and we wont be able to mount this until it is in a clean state. We see that he log required was 1829641-1829643 (0x1beb09-0x1beb0b). If you look at the log folder, you might be able to find these logs (they should exist – they were created, but the dbTime is “too old”). Look at the first three letters that start off on the log file. In my situation was E070. Remember that. 

Lets go back to our command prompt that is already in the /Exchange Server/BIN folder. From there we would run the following command:

ESEUTIL /R E07 /l<driveletter>:\Log_Location

The reason I am selecting to replay the logs starting with E07 is because the formatting of the command (ESEUTIL /R Enn – Enn = the base log that needs to be replayed). Because I know Log 0x1beb09 = E0700001beb09, I should replay the logs for E07.

Monitor the process as it runs..

Initiating RECOVERY mode…

Logfile base name: E07

Log files: L:\LogLocation

System files: <current directory>

Performing soft recovery…

Restore Status (% complete)

0    10   20   30   40   50   60   70   80   90  100

|—-|—-|—-|—-|—-|—-|—-|—-|—-|—-|

……………………………………………

Once this is completed you should have no errors. Check out the status of your DB utilizing ESEUTIL /MH. The db should show a clean shutdown state with 0×0 logs required (meaning there are no logs that are required for the db to replay):

Initiating FILE DUMP mode…

Database: F:\NAData21\NAMailboxDatabase21.edb

File Type: Database

Format ulMagic: 0x89abcdef

Engine ulMagic: 0x89abcdef

Format ulVersion: 0×620,12

Engine ulVersion: 0×620,12

Created ulVersion: 0×620,12

DB Signature: Create time:09/15/2010 16:58:36 Rand:2592704934 Computer:

cbDbPage: 8192

dbtime: 4104664568 (0xf4a835f8)

State: Clean Shutdown

Log Required: 0-0 (0×0-0×0)

Once you have also replayed the logs, the dbTime log sequencing is also updated so that logs will be stamped once the DB is mounted.

Attempt to mount your database again and you should be good.

Any questions leave them below in the comments section.

(and for the Redditors who read this)

TL;DR: Don’t run ESEUTIL /P as your first step! /P = Panic = :( data loss! Run ESEUTIL /MH to get the status of the DB and then run ESEUTIL /R if you are able to find the logs / restore the logs.

-Adam F

About these ads

4 thoughts on “How to solve ESE -566 Errors (JET_errDbTimeTooOld)

  1. I have this error but appears when I run Eseutil /R … is there any way to fix it? in my case my DB came from a WIndows Backup and was Restored in File Mode (not app mode)… My users are in DialTone … and frankly i don’t want to run eseutil /p with a 137 GB database (it’s remind me when I was an exchange 2000 admin :D) – please forgive my english!!!

    • So the situation I wrote about above covers when the logs are not corrupt, but the dbTime is off. It is kind of weird you are getting this when attempting ESEUTIL /R but here are a few pointers (exchange 2007+)..

      Run ESEUTIL /ML against the logs. This should check the checksum to ensure nothing is corrupt. If everything is ok, then I would simply move the checkpoint to a different location and then run this..

      ESEUTIL /R E00 /L

      If this fails, you can run the following below..

      ESEUTIL /R E /L /A

      The /A will allow you to essentially replay the database with the logs available, and assume a loss for the logs that are unable to replay. It is cleaner than ESEUTIL /P but you are still assuming a loss of data.

      Unfortunetly if you are not able to get anything replayed back then you are in a tight situation and will probably need to run ESEUTIL /P.

      • The corruption was in e00.log… I’ve run with /a switch with failed database (removing e00.log) and with the restored database (with logs restored and the logs in the failed Database) the timestamp error appears in both trys – eseutil /ml gave me ok… after that… lost by lost (perdido por perdido in spanish :D) … I started to run eseutil /p. Because the corruption appears at e00.log the process run very quicky (137 gb in a dell r710 with raid 10 sata disk – exchange installed on a VM with hyper-v with a fixed disk – took aprox. two hours) because the database has no issues with pages… or at least integrity and checksum check gave me no error – After that, the recovery operation with restore-mailbox works fine. To avoid isinteg I will run a full move mailbox operation this weekend… In the case of a Move Failure i will evaluate Isinteg depending of the user mailbox. Thanks For the help!!!

      • Not a problem pal. Thank you for stopping by.

        btw – I dont know what version you are running but ISINTEG is depreciated / no longer exists in Exchange 2010. You should run the online repair, which is New-MailboxRepairRequest. That will take care of the integrity / corruption on a mounted database you might have.

        The last thing (and I don’t remember why your DB went offline) would be to create a new DB and then move these guys off. You don’t want that happening again :D

        New-MailboxRepairRequest: http://technet.microsoft.com/en-us/library/ff625226(v=EXCHG.141).aspx

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s