Strange behavior with List.ForEach(Action) and a Sql Transaction

Question

Scenario

I'm writing a system to carry out exams. The person in charge of the exam (Invigilator) starts the exam, and at that point, the people taking the exam (Candidates) are permitted to start. If a candidate tries to start prematurely they receive a message telling them to wait for the invigilator. Both start times are logged (Exam Start and Candidate Start).

When the invigilator starts the exam we set the exam start time for the exam, we then find out how much time each candidate is allowed to have on the exam, and add it to the exam start time, thus giving us what I call their scheduled finish.

public void SetExamStart(Exam exam, List<ExamCandidate> examCandidates)
{
    DateTime startTime = _timeService.GetCurrentDateTime();

    exam.ExamStarted = startTime;

    _work.ExamRepository.Update(exam);

    examCandidates.ForEach(ec =>
    {
        ExamPaper examPaper = ec.ExamPaper;

        if (!examPaper.ExamDuration.HasValue)
        {
            return;
        }

        Int32 examPaperDuration = examPaper.ExamDuration.Value;

        DateTime scheduledFinish = startTime.AddMinutes(examPaperDuration);

        ec.ScheduledFinish = scheduledFinish;

        _work.ExamCandidateRepository.Update(ec);
    });
}

The calls to the repositories are within the same transaction. ConnectionService is dependency injected into the repository, and the repository is injected into UnitOfWork (_work), both on per web request basis.

public virtual void Update(TEntity entity)
{
    IDbConnection connection = ConnectionService.Connection;

    try
    {
        connection.Execute(_queryGenerator.UpdateQuery, entity, ConnectionService.Transaction);
    }
    catch (SqlException ex)
    {
        throw new DataAccessException("An error occured on query execution", ex);
    }            
}

When a candidate attempts to start:

public void StartCandidateExam(Guid examCandidateId)
{
    ExamCandidate examCandidate = _work.ExamCandidateRepository.Get(examCandidateId);

    Exam exam = examCandidate.Exam;

    if (!exam.ExamStarted.HasValue) {
        throw new ExamNotStartedException("Please wait for the invigilator to start the exam");
    }

    _candidateExamService.StartExam(examCandidate);

    _work.SaveChanges();
}

public void StartExam(ExamCandidate examCandidate)
{
    DateTime currentTime = _timeService.GetCurrentDateTime();

    examCandidate.Started = currentTime;

    _work.ExamCandidateRepository.Update(examCandidate);
}

Throughout this project I use a Lazy<T> on some entities. Such as the ExamPaper property on the ExamCandidate entity. This is shown below:

public class ExamCandidate
{
    //other properties

    public DateTime? ScheduledFinish { get; set; }

    public int ExamPaperID { get; set; }

    public LazyEntity<ExamPaper> ExamPaper { get; set; }
}

public class LazyEntity<T> : Lazy<T>
{
    public LazyEntity(Func<T> func) : base(func) {}

    public static implicit operator T(LazyEntity<T> lazy)
    {
        return lazy.Value;
    }
}

// setting the lazy in the exam candidate repository
examCandidate.ExamPaper = new LazyEntity<ExamPaper>(() =>
{
    return Work.ExamPaperRepository.Get(examCandidate.ExamPaperID);
});

Problem:

A candidate started their exam very soon after the invigilator which has resulted in their ScheduledFinish not being set. This has worked fine for the other candidates that started a few seconds after.

Here are the logs:

+------------------------+-------------------------+
|       Log Type         |        Log Date         |
+------------------------+-------------------------+
| Exam Started           | 2018-03-08 15:00:58.370 |
| Candidate Exam Started | 2018-03-08 15:00:58.387 |
+------------------------+-------------------------+

+-------------------------+-------------------------+--------+-------------+
|         Started         |     ScheduledFinish     | ExamID | ExamPaperID |
+-------------------------+-------------------------+--------+-------------+
| 2018-03-08 15:00:58.387 | NULL                    |     42 |          34 |
| 2018-03-08 15:01:01.727 | 2018-03-08 15:30:58.370 |     42 |          34 |
| 2018-03-08 15:01:02.507 | 2018-03-08 15:30:58.370 |     42 |          56 |
| 2018-03-08 15:01:02.770 | 2018-03-08 15:30:58.370 |     42 |          56 |
| 2018-03-08 15:01:02.960 | 2018-03-08 15:30:58.370 |     42 |          34 |
+-------------------------+-------------------------+--------+-------------+

I cannot see a reason for this, the starting of the exam and the setting of each scheduled finish is done in the same operation, under the same transaction and a candidate cannot start until this has happened.

Is there something I'm missing?

--Edit To clarify, this problem has happened twice in a little under a year. Both times the candidate has started very soon after the invigilator started.

@LasseVågsætherKarlsen Did you mean `ec.ExamPaper`? `ExamDuration` is just a `int?` on the `ExamPaper` entity. — Jack Pettinger, Mar 09 '18 at 13:07
Show the method where you write the `Candidate Started` value. How do you protect against concurrency? — nvoigt, Mar 09 '18 at 13:07
Is it possible that the `ExamDuration` of the `ExamPaper` is not set for the first canidate since that would hit the `if` that skips setting the scheduled finish? — juharr, Mar 09 '18 at 13:07
Why are you putting the individual starts in the same transaction as the exam start? I would think you'd want to start the exam, commit that, then start each individual in their own transaction. Do you really want to undo the entire exam if a single candidate update fails? — Colin Young, Mar 09 '18 at 13:12
I can't see how this is answerable, there are far too many moving parts here. The best placed person to answer this is you. The only thing that'd help would be if you created a [**Minimal**, Complete, and Verifiable example](https://stackoverflow.com/help/mcve) of your problem, but if you could do that you'd know what the problem is — Liam, Mar 09 '18 at 13:24
I believe your error is related to you updating the first exam and then working through the examCandidates. Put a break point on your return statement and see if it's getting hit the first run through. — Michael Puckett II, Mar 09 '18 at 13:35
No, I meant, what does the property look like, it's complete declaration and implementation. — Lasse V. Karlsen, Mar 10 '18 at 17:53

Ive · Answer 1 · 2018-03-09T14:31:36.303

I think your problem is that you first sets exam.ExamStarted = startTime in SetExamStart and than ScheduledFinish for candidates. Than is possible to call StartCandidateExam because ExamStarted.HasValue is true, but your ExamCandidate ScheduledFinish can be null.

Change your SetExamStart to this to be sure that ScheduledFinish is set:

public void SetExamStart(Exam exam, List<ExamCandidate> examCandidates)
{
    DateTime startTime = _timeService.GetCurrentDateTime();

    examCandidates.ForEach(ec =>
    {
       ExamPaper examPaper = ec.ExamPaper;

       if (!examPaper.ExamDuration.HasValue)
       {
          return;
       }

       Int32 examPaperDuration = examPaper.ExamDuration.Value;

       DateTime scheduledFinish = startTime.AddMinutes(examPaperDuration);

       ec.ScheduledFinish = scheduledFinish;

       _work.ExamCandidateRepository.Update(ec);
    });

    exam.ExamStarted = startTime;

   _work.ExamRepository.Update(exam);
}

it is possible that you must change this logik

 if (!examPaper.ExamDuration.HasValue) 
 ...

too.

Strange behavior with List.ForEach(Action) and a Sql Transaction

1 Answers1