AD eventid 1917 appears only sometimes

[VladV]

I recently watched a webinar regarding AD / virtualization and VBR and the moderator mentioned that the eventid id 1917 under Active Directory Domain Services events should accompany every successful backup.

I verified my active directory servers and saw just a few scattered Backup events with eventid 1917 without any logic of the dates in particular. They only seem to be generated by the replication process and not by backup, but, again, not all the time. I am running on 2008 R2 and VBR 7 with successful SureBackups of the ADs every day.

So, what's the explanation on this?

Thanks.

[Shestakov]

Hello Vlad,

Event id 1917 accompanies successful Shadow Copy Backup for Active Directory procedure to be exact.
The question why it appears not all the time is an interesting one. I`ll elaborate on this with our QA team.

Could you please give more info about the jobs you did and the results you had? Were all of them successful, which types of jobs had the id, which not?
Thank you.

[VladV]

I have 3 AD/DC servers on 2008 R2.
For the first one I see 8 events at the following dates that correspond to the job type on the right:

Code: Select all

1/4/14 12:01 - Rep
1/7/14 12:01 - Rep
1/10/14 12:02 - Rep
2/4/14 20:34 - Backup
2/14/2014 5:00:57 PM - Rep
6/30/2014 1:08:04 PM - Rep
6/30/2014 5:01:09 PM - Rep
9/24/2014 5:01:18 PM - Rep

They all match replication jobs with one exception, although, daily I have 2 replication jobs for these ADs at 12:00 and 17:00, and 1 backup job at 18:00. The replication jobs are set to use AAIP and not to truncate logs.

For the second one I see 16 events:

Code: Select all

9/7/2013 5:01:32 PM - Rep
9/12/2013 5:01:19 PM - Rep
9/12/2013 11:37:40 PM - Backup
10/10/2013 9:48:24 PM - Backup
10/14/2013 3:24:39 PM - Rep
10/14/2013 9:21:33 PM - Backup
10/17/2013 10:40:55 AM - Backup
11/22/2013 9:54:21 PM - Backup
12/20/2013 5:04:05 PM - Rep
1/21/2014 5:04:48 PM - Rep
1/22/2014 12:05:39 PM - Rep
4/2/2014 8:43:13 PM - Backup
6/30/2014 12:06:16 PM - Rep
9/17/2014 5:06:00 PM - Rep
10/1/2014 12:08:24 PM - Rep
10/7/2014 5:03:29 PM - Rep

In 2013 I had a different backup and replication scheme. Daily I had replication jobs at 12:00 and 17:00 during weekdays and only at 17:00 during weekends. Backups were after 17:00 once a day, and a full on Saturday (same for the first AD). Of course some of them (the ones that don't respect the schedule mentioned earlier) were run manually due to different maintenance operations.

Again, I see no errors during backups or replications and the event log looks like this for both replication and backup jobs and on both ADs under Windows Logs > Application:

Code: Select all

Information	8/10/14 6:16 PM	VSS	        8224	None The VSS service is shutting down due to idle timeout. 
Information	8/10/14 6:04 PM	ESENT	103	General lsass (520) The database engine stopped the instance (1).
Information	8/10/14 6:04 PM	ESENT	302	Logging/Recovery lsass (520) The database engine has successfully completed recovery steps.
Information	8/10/14 6:04 PM	ESENT	301	Logging/Recovery lsass (520) The database engine has begun replaying logfile \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy10\Windows\NTDS\edb.log.
Information	8/10/14 6:04 PM	ESENT	216	Logging/Recovery lsass (520) A database location change was detected from 'C:\Windows\NTDS\ntds.dit' to '\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy10\Windows\NTDS\ntds.dit'.
Information	8/10/14 6:04 PM	ESENT	301	Logging/Recovery lsass (520) The database engine has begun replaying logfile \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy10\Windows\NTDS\edb00278.log.
Information	8/10/14 6:04 PM	ESENT	216	Logging/Recovery lsass (520) A database location change was detected from 'C:\Windows\NTDS\ntds.dit' to '\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy10\Windows\NTDS\ntds.dit'.
Information	8/10/14 6:04 PM	ESENT	300	Logging/Recovery lsass (520) The database engine is initiating recovery steps.
Information	8/10/14 6:04 PM	ESENT	102	General lsass (520) The database engine (6.01.7601.0000) started a new instance (1).
Information	8/10/14 6:04 PM	ESENT	2006	ShadowCopy certsrv (1392) Shadow copy instance 5 completed successfully.
Information	8/10/14 6:04 PM	ESENT	2006	ShadowCopy lsass (520) Shadow copy instance 5 completed successfully.
Information	8/10/14 6:04 PM	ESENT	2003	ShadowCopy certsrv (1392) Shadow copy instance 5 freeze ended.
Information	8/10/14 6:04 PM	ESENT	2006	ShadowCopy svchost (1516) Shadow copy instance 5 completed successfully.
Information	8/10/14 6:04 PM	ESENT	2006	ShadowCopy wins (3224) Shadow copy instance 5 completed successfully.
Information	8/10/14 6:04 PM	ESENT	2003	ShadowCopy wins (3224) Shadow copy instance 5 freeze ended.
Information	8/10/14 6:04 PM	ESENT	2003	ShadowCopy lsass (520) Shadow copy instance 5 freeze ended.
Information	8/10/14 6:04 PM	ESENT	2003	ShadowCopy svchost (1516) Shadow copy instance 5 freeze ended.
Information	8/10/14 6:04 PM	ESENT	2001	ShadowCopy wins (3224) Shadow copy instance 5 freeze started.
Information	8/10/14 6:04 PM	ESENT	2001	ShadowCopy certsrv.exe (1392) Shadow copy instance 5 freeze started.
Information	8/10/14 6:04 PM	ESENT	2001	ShadowCopy svchost (1516) Shadow copy instance 5 freeze started.
Information	8/10/14 6:04 PM	ESENT	2001	ShadowCopy wins (3224) Shadow copy instance 5 freeze started.
Information	8/10/14 6:04 PM	ESENT	2001	ShadowCopy certsrv (1392) Shadow copy instance 5 freeze started.
Information	8/10/14 6:04 PM	ESENT	2001	ShadowCopy lsass (520) Shadow copy instance 5 freeze started.
Information	8/10/14 6:04 PM	ESENT	2005	ShadowCopy wins (3224) Shadow copy instance 5 starting. This will be a Full shadow copy.
Information	8/10/14 6:04 PM	ESENT	2005	ShadowCopy svchost (1516) Shadow copy instance 5 starting. This will be a Full shadow copy.
Information	8/10/14 6:04 PM	ESENT	2005	ShadowCopy lsass (520) Shadow copy instance 5 starting. This will be a Full shadow copy.
Information	8/10/14 6:04 PM	ESENT	2005	ShadowCopy certsrv (1392) Shadow copy instance 5 starting. This will be a Full shadow copy.

and under Active Directory Domain Services logs for the backup job above:
Information 8/10/14 6:04 PM NTDS ISAM 2001 (16) NTDS (520) NTDSA: Shadow copy instance 5 freeze started.

[Shestakov]

Thank you for the info, Vlad!

Our QA will look into the issue.
I`ll let you know once we`ve got some results on that.

[Beard]

Wondering if QA found anything on this?

[Shestakov]

Yeah, sorry for the delay.

They made some testing and found out that the event is generated by AD and generation logic can vary from one OS version to another, Veeam Backup and Replication itself doesn`t evoke the event.
If you want to be sure that your application is set to take a System State backup and use the VSS writer, then look in the “Application” log for several Event 2001 and Event 2003 entries generated by ESENT. If there are no associated errors, then your directory is being safely backed up.

What is your use case by the way?
If something goes wrong with VSS processes VBR generates and error and fails the job.
Thank you.

[Beard]

Thank you, Shestakov. I was working on case 00743830. I assumed it was some peculiarity in the way the event ID was generated, but wanted to confirm this.