User Profile Change Logging

Profile Change Logging

There is a table in the SSP database named UserProfileEventLog. The table maintains a history of user profile property changes. By default, it retains 7 days of history. This table can cause problems in a couple of ways.

First issue: size. This table contains one row per change of a property in a user profile. The row contains the old and new property values, along with associated metadata like the datetime the property was changed. The implication is that the table can grow large. Assume you just configured the profile import and are ready to start the first Active Directory import. Further, assume your organization has 100,000 user accounts, and each account be populated with 12 AD attributes.  The full import will result in 100,000 X 12 = 1.2 millions rows being inserted into UserProfileEventLog.  To extend the example, assume you also have a BDC import connection populating another 20 properties from your company's HR system. That adds another 2 million rows. There are now 3.2 million rows in the event log table.  If each row is 100 bytes (old value, new value, plus metadata), the table is now approximately 300 MB in size.

Second issue: deleting old entries. The change history is kept for a configurable number of days. The concern is how many rows will have to be deleted on a given day? The number of days of history is 7 days be default, but can be set using stsadm.exe -o profilechangelog -title <SSP Name> -daysofhistory <number of days> -generateanniversaries (http://technet.microsoft.com/en-us/library/cc263013.aspx).  The critical issue is that MOSS has to remove a full day of history every day to honor the daysofhistory setting. Using the numbers in the preceding paragraph, 7 days after the first full import, MOSS is going to delete 3.2 millions rows of data all at once!  What makes this an issue is that this is done with a single SQL statement, something like DELETE FROM  UserProfileEventLog WHERE EventId < @MinEventTime. Think of the implications. As a single statement, this will hold locks until all 3.2 million rows are deleted. These locks might prevent other database transactions from completing; but it also means the transaction log (even with simple recovery mode) cannot be truncated, and will therefore grow until at least this DELETE statement completes. I have seen this delete statement run for 4 hours, with the transaction log quadrupling in size.

This is little you can do to avoid this. Although you can adjust the number of days of history, MOSS will eventually try to delete an entire day's history at some point. The deletion is done by an internal timer job buried within the SSP. The job is hard coded to run at 10:00 PM daily. You cannot change this scheduled time.

What are the take-aways?

• 1. Be prepared for an occasional long running DELETE statement. Ensure you have sufficient transaction log space to accommodate the potential transaction log growth.
  
• 2. Don't schedule any other timer jobs or database maintenance for 10:00 PM to minimize possible deadlocks and transaction timeouts.
  
• 3. Be careful using stsadm -o profilechangelog to reduce the number of days of history, because the next time 10:00 PM comes, MOSS will try to delete multiple days of history all at once.