AuditerBase + transaction for non-interested items

Posts   
 
    
Posts: 69
Joined: 24-Jun-2008
# Posted on: 20-Aug-2010 15:10:07   

When I have a auditor, I am currently only interested in updates and deletes. However, when inserting items, the query returns a time-out.

After some investigation, it seems that I had to implement something like this:

public override bool RequiresTransactionForAuditEntities(SingleStatementQueryAction actionToStart)
{
    switch (actionToStart)
    {
        case SingleStatementQueryAction.DirectUpdateEntities:
        case SingleStatementQueryAction.DirectDeleteEntities:
        case SingleStatementQueryAction.NewEntityInsert:
            // Do not use transaction
            return false;

        default:
            // Use transaction
            return true;
    }
}

Don't you think it's strange that a query times out, just because I don't override the methods for DirectUpdateEntities, DirectDeleteEntities and for this case specific, the NewEntityInsert?

Also, the audit example is a bit weird. In the GetAuditEntitiesToSave method, it always returns the list although the documentation says that null should be passed in case there are no items to save. First I thought this was the problem, but returning null in case there were no items in the list didn't fix the timeout.

daelmo avatar
daelmo
Support Team
Posts: 8245
Joined: 28-Nov-2005
# Posted on: 21-Aug-2010 05:41:31   

Hi Geert,

Could you please atach your auditor class? Also, please post the exception message and stack trace to understand what is going on.

David Elizondo | LLBLGen Support Team
Posts: 69
Joined: 24-Jun-2008
# Posted on: 23-Aug-2010 13:22:37   

Thank you for your reply. Here is the code (this one works, since I correctly added the fix in the RequiresTransactionForAuditEntities method):


#region Enums
/// <summary>
/// Change type.
/// </summary>
internal enum AuditType
{
    /// <summary>
    /// The record was updated. The specific fields that were updated are included. Therefore, it is possible
    /// that multiple update entries for one entity are located in the auditing log.
    /// </summary>
    Update,

    /// <summary>
    /// The record was deleted.
    /// </summary>
    Delete
}
#endregion

/// <summary>
/// Auditor that writes the database changes to a database table.
/// </summary>
internal class DbAuditor : AuditorBase
{
    #region Constants
    #endregion

    #region Variables
    private static readonly List<string> _fieldsToIgnore = new List<string>();

    private readonly List<AuditTrailEntity> _auditTrailEntities = new List<AuditTrailEntity>();
    #endregion

    #region Constructor & destructor
    /// <summary>
    /// Initializes a new instance of the <see cref="DbAuditor"/> class.
    /// </summary>
    static DbAuditor()
    {
        lock (_fieldsToIgnore)
        {
            // Initialize fields to ignore
            _fieldsToIgnore.Add("CreationDate");
            _fieldsToIgnore.Add("CreatedBy");
            _fieldsToIgnore.Add("ModificationDate");
            _fieldsToIgnore.Add("ModifiedBy");
        }
    }
    #endregion

    #region Properties
    #endregion

    #region Methods
    /// <summary>
    /// Constructs the audit info for an entity.
    /// </summary>
    /// <param name="entity">The entity.</param>
    /// <param name="type">The audit type.</param>
    /// <returns>
    /// Array of <see cref="AuditTrailEntity"/> objects.
    /// </returns>
    private static AuditTrailEntity[] ConstructAuditInfo(IEntityCore entity, AuditType type)
    {
        List<AuditTrailEntity> auditTrails = new List<AuditTrailEntity>();

        foreach (IEntityField entityField in entity.Fields)
        {
            // Should we ignore this field?
            if (_fieldsToIgnore.Contains(entityField.Name)) continue;

            if (type != AuditType.Delete)
            {
                // Check if this field is different, only store changed fields
                if (entityField.DbValue == entityField.CurrentValue) continue;
            }

            AuditTrailEntity auditTrail = new AuditTrailEntity();
            auditTrail.TableName = GetTableName(entity);
            auditTrail.RecordID = GetRecordID(entity);
            auditTrail.FieldName = entityField.SourceColumnName;
            auditTrail.UserName = DbUtils.WindowsUserName;
            auditTrail.OldValue = ConvertValueToString(entityField.DbValue);
            auditTrail.NewValue = (type != AuditType.Delete) ? ConvertValueToString(entityField.CurrentValue) : null;
            auditTrail.EventType = type.ToString().ToLower();

            auditTrails.Add(auditTrail);
        }

        return auditTrails.ToArray();
    }

    /// <summary>
    /// Determines whether this instance can audit the specified entity.
    /// </summary>
    /// <param name="entity">The entity.</param>
    /// <returns>
    ///     <c>true</c> if this instance can audit the specified entity; otherwise, <c>false</c>.
    /// </returns>
    private static bool CanAuditEntity(IEntityCore entity)
    {
        if (entity == null) return false;
        if (entity is AuditTrailEntity) return false;
        return true;
    }

    /// <summary>
    /// Converts the value to string.
    /// </summary>
    /// <param name="value">The value.</param>
    /// <returns>The string representation of the value.</returns>
    private static string ConvertValueToString(object value)
    {
        if (value == null) return null;
        if (value is Byte[]) return "binary";
        return value.ToString();
    }

    /// <summary>
    /// Gets the record ID of a specific entity, which is a combination of all primary keys.
    /// </summary>
    /// <param name="entity">The entity.</param>
    /// <returns>Record ID.</returns>
    private static string GetRecordID(IEntityCore entity)
    {
        if (entity == null) throw new ArgumentNullException("entity");

        string recordID = string.Empty;
        foreach (IEntityField primaryKeyField in entity.PrimaryKeyFields)
        {
            // Get value
            object value = primaryKeyField.CurrentValue;
            string stringValue = (value != null) ? value.ToString() : "null";

            // Is this the first one?
            if (string.IsNullOrEmpty(recordID))
            {
                recordID = stringValue;
            }
            else
            {
                recordID += string.Format(", {0}", stringValue);
            }
        }
        return recordID;
    }

    /// <summary>
    /// Gets the name of the table.
    /// </summary>
    /// <param name="entity">The entity.</param>
    /// <returns>The table name.</returns>
    private static string GetTableName(IEntityCore entity)
    {
        if (entity == null) throw new ArgumentNullException("entity");

        IEntityField field = entity.Fields[0] as IEntityField;
        return (field != null) ? field.SourceObjectName : "unknown, no fields";
    }
        
    /// <summary>
    /// Audits the successful update of an existing entity in the database
    /// </summary>
    /// <param name="entity">The entity updated successfully in the database.</param>
    public override void AuditUpdateOfExistingEntity(IEntityCore entity)
    {
        if (!CanAuditEntity(entity)) return;

        _auditTrailEntities.AddRange(ConstructAuditInfo(entity, AuditType.Update));
    }

    /// <summary>
    /// Audits the successful delete of an entity from the database
    /// </summary>
    /// <param name="entity">The entity which was deleted.</param>
    /// <remarks>As the entity passed in was deleted succesfully, reading values from the passed in entity is only possible in this routine. After this call, the
    /// state of the entity will be reset to Deleted again and reading the fields will result in an exception. It's also recommended not to reference
    /// the passed in entity in any audit entity you might want to persist as the entity doesn't exist anymore in the database.</remarks>
    public override void AuditDeleteOfEntity(IEntityCore entity)
    {
        if (!CanAuditEntity(entity)) return;

        _auditTrailEntities.AddRange(ConstructAuditInfo(entity, AuditType.Delete));
    }

    /// <summary>
    /// Method which returns true if this auditor expects to have audit entities to persist and therefore needs a transaction.
    /// This method is called in the situation when there's no transaction going on though one should be started right before the single-statement action
    /// in the case if the auditor has entities to save afterwards. It's recommended to return true if the auditor might have audit entities
    /// to persist after an entity save/delete/direct update/direct delete of entities. Default: true
    /// </summary>
    /// <param name="actionToStart">The single statement action which is about to be started.</param>
    /// <returns>
    /// true if a transaction should be started prior to the action to perform (entity save/delete/direct update/direct delete of entities)
    /// false otherwise.
    /// </returns>
    /// <remarks>If false is returned and GetAuditEntitiesToSave returns 1 or more entities, a new transaction is started to save these audit entities
    /// which means that this transaction isn't re-tryable if this transaction might fail.</remarks>
    public override bool RequiresTransactionForAuditEntities(SingleStatementQueryAction actionToStart)
    {
        switch (actionToStart)
        {
            case SingleStatementQueryAction.DirectUpdateEntities:
            case SingleStatementQueryAction.DirectDeleteEntities:
            case SingleStatementQueryAction.NewEntityInsert:
                // Do not use transaction
                return false;

            default:
                // Use transaction
                return true;
        }
    }

    /// <summary>
    /// Gets the audit entities to save. Audit entities contain the audit information stored inside this auditor.
    /// </summary>
    /// <returns>
    /// The list of audit entities to save, or null if there are no audit entities to save
    /// </returns>
    /// <remarks>Do not remove the audit entities and audit information from this auditor when this method is called, as the transaction in which
    /// the save takes place can fail and retried which will result in another call to this method</remarks>
    public override System.Collections.IList GetAuditEntitiesToSave()
    {
        return _auditTrailEntities;
    }

    /// <summary>
    /// The transaction with which the audit entities requested from GetAuditEntitiesToSave were saved.
    /// Use this method to clear any audit data in this auditor as all audit information is persisted successfully.
    /// </summary>
    public override void TransactionCommitted()
    {
        _auditTrailEntities.Clear();
    }
    #endregion
}

Walaa avatar
Walaa
Support Team
Posts: 14950
Joined: 21-Aug-2005
# Posted on: 23-Aug-2010 16:23:18   

You should ovverride RequiresTransactionForAuditEntities to specify based on thhe action being audit, if you want to save the audit entities in the same transaction or not.

Is there a chance you were auditing actions on an Audit entity? If not, how do you inject the Auditor to your entities, coz i don't see any DI attribute decoration the auditor class.

Posts: 69
Joined: 24-Jun-2008
# Posted on: 24-Aug-2010 09:57:30   

I have overriden the CreateAuditor method in CommonEntityBase. This is because I have introduced an ExcludeFromAuditAttribute which I can use to decorate entities that I don't want to decorate.

I must admit that I haven't decorated the AuditTrail entity with the attribute. Will test it and report back.

Btw. I didn't receive a "new update e-mail" on the thread by e-mail for the 2nd post. Is that a know issue? It happens more that I have to "poll" the website for new updates on threads.

Posts: 69
Joined: 24-Jun-2008
# Posted on: 24-Aug-2010 10:06:14   

I have now excluded the AuditTrailEntity from the auditing by using the ExcludeFromAudit attribute. However, I already checked in the auditor itself whether an entity should be audited (by checking if the entities in the update methods were of type AuditTrail).

However, the timeout still exists. Here is the stacktrace:


SD.LLBLGen.Pro.ORMSupportClasses.ORMQueryExecutionException: An exception was caught during the execution of an action query: Time-out is verlopen. De time-outperiode is verstreken voordat de bewerking werd voltooid of de server reageert niet.
The statement has been terminated.. Check InnerException, QueryExecuted and Parameters of this exception to examine the cause of this exception. ---> System.Data.SqlClient.SqlException: Time-out is verlopen. De time-outperiode is verstreken voordat de bewerking werd voltooid of de server reageert niet.
The statement has been terminated.
   bij System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   bij System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
   bij System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
   bij System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   bij System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
   bij System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
   bij System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
   bij System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)
   bij System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
   bij SD.LLBLGen.Pro.ORMSupportClasses.ActionQuery.Execute()
   --- Einde van intern uitzonderingsstackpad ---
   bij SD.LLBLGen.Pro.ORMSupportClasses.ActionQuery.Execute()
   bij SD.LLBLGen.Pro.ORMSupportClasses.BatchActionQuery.Execute()
   bij SD.LLBLGen.Pro.ORMSupportClasses.DaoBase.ExecuteActionQuery(IActionQuery queryToExecute, ITransaction containingTransaction)
   bij SD.LLBLGen.Pro.ORMSupportClasses.DaoBase.AddNew(IEntityFields fields, ITransaction containingTransaction)
   bij MyCompany.DAL.EntityClasses.OrderEntity.InsertEntity() in MyCompany\DAL\OrderEntity.g.cs:regel 753
   bij SD.LLBLGen.Pro.ORMSupportClasses.EntityBase.CallInsertEntity()
   bij SD.LLBLGen.Pro.ORMSupportClasses.DaoBase.PersistQueue(List`1 queueToPersist, Boolean insertActions, ITransaction transactionToUse, Int32& totalAmountSaved)
   bij SD.LLBLGen.Pro.ORMSupportClasses.EntityBase.Save(IPredicate updateRestriction, Boolean recurse)
   bij Verbeeten.Data.PRDB.EntityClasses.CommonEntityBase.Save(IPredicate updateRestriction, Boolean recurse) in C:\Source\Core\src\Verbeeten.Data.PRDB\EntityClasses\CommonEntityBase.cs:regel 768

Thanks to the system administrators, the .NET Framework keeps installing the dutch language pack (I don't need dutch exceptions), but anyway, it's a time-out issue.

Otis avatar
Otis
LLBLGen Pro Team
Posts: 39614
Joined: 17-Aug-2003
# Posted on: 24-Aug-2010 12:45:25   

(about email: they are sent, but it might be they're blocked at your mail server as 'spam')

It looks like a deadlock, i.e. separate connections are used to persist the entities for auditing and the real ones. When you always return true from RequiresTransactionForAuditEntities, does that solve the problem?

Frans Bouma | Lead developer LLBLGen Pro
Posts: 69
Joined: 24-Jun-2008
# Posted on: 30-Aug-2010 10:06:34   

(strange, because I did receive the first e-mail, is the template of the second one different?)

The problem occurs when I always return true. Now I have created the custom switch statement, the deadlock dissappears.

Otis avatar
Otis
LLBLGen Pro Team
Posts: 39614
Joined: 17-Aug-2003
# Posted on: 30-Aug-2010 15:21:21   

It works OK. It will send an email when another person than yourself has posted a message. So you can't test it yourself by posting a new message, it's not sending a notification (as you posted the last post wink ).

The pattern isn't changed but perhaps your ISP or system admin enrolled new anti-spam features...

Frans Bouma | Lead developer LLBLGen Pro
Posts: 69
Joined: 24-Jun-2008
# Posted on: 30-Aug-2010 15:23:54   

Now I have received 2 update e-mail (one on 1500, one on 1521).

But, back to topic. Do you have any idea why the transaction hangs when I simply return true always (because that's the default value, and when I use the default value, the transaction is being locked).

DvK
User
Posts: 318
Joined: 22-Mar-2006
# Posted on: 30-Aug-2010 21:41:22   

This thread discusses almost the same thing : http://www.llblgen.com/tinyforum/Messages.aspx?ThreadID=14962

Posts: 69
Joined: 24-Jun-2008
# Posted on: 01-Sep-2010 10:56:19   

I can't see how the topics are related.

DvK
User
Posts: 318
Joined: 22-Mar-2006
# Posted on: 01-Sep-2010 11:05:38   

Scroll down to my first (and other) messages by DvK. I was (still) having the same time-out issue while auditing an updated entity and tried to fetch the entity's current fieldvalues within a TypedList.

This seems related to me...

Regards, Danny