IIS托管Web应用线程内方法末尾日志偶发缺失问题排查

Let’s dig into why that final "Method Ended" log line in your ResetEmployeeAssignedCoursesByRole method is sometimes missing, and walk through practical fixes to resolve the issue.

Possible Causes & Fixes #

1. IIS App Pool Recycling or Thread Abortion #

When you use a raw Thread to run background work in IIS, there’s no guarantee the thread will finish before the app pool recycles, or before the parent request completes and IIS cleans up resources. If the thread gets terminated mid-execution (right after CommitTransaction but before the final log), your log line never runs.

Fixes:

• Replace direct Thread creation with IIS-friendly background task mechanisms:
  • For .NET Framework, use HostingEnvironment.QueueBackgroundWorkItem (it tells IIS to wait for the task to finish before recycling):

    HostingEnvironment.QueueBackgroundWorkItem(token => ResetEmployeeAssignedCoursesByRole());
    

  • For .NET Core+, use IHostedService or BackgroundService for long-running/background tasks.
• Check your IIS app pool recycling settings (in IIS Manager → Application Pools → Your Pool → Recycling) to see if recycling is happening around the time logs go missing. Enable recycling logs to confirm.

2. File Locking Race Condition & Swallowed Exceptions #

Your createRoleLog method checks if the file is locked, then tries to write—but there’s a tiny window between the check and opening the file where another thread could lock it. Worse, the catch block in createRoleLog swallows exceptions entirely, so you never see when the write fails.

Fixes:

• Remove the IsFileLocked check—it’s not atomic and doesn’t prevent race conditions. Instead, handle locking directly in the write logic.
• Stop swallowing exceptions in createRoleLog. Log failures to the Windows Event Log (so you can see why writes fail):

  catch (Exception ex)
  {
      EventLog.WriteEntry("YourWebAppName", $"Failed to write role log: {ex.ToString()}", EventLogEntryType.Error);
  }
  

• Simplify file writing with File.AppendAllText—it handles file opening/closing safely and reduces boilerplate:

  // Replace the entire FileStream/StreamWriter block with this
  var logContent = empHdrID != 0 
      ? $"-------- [empHdrID: {empHdrID}] {DateTime.Now} --------\n{errorMessage}\n------------------------\n"
      : $"-------- {DateTime.Now} --------\n{errorMessage}\n------------------------\n";
  
  File.AppendAllText(path, logContent);
  

3. Transaction Commit Exceptions Skipping the Log #

If dbTransactionHelper.CommitTransaction() throws an exception, the code jumps straight to the catch block—so your final "Ended" log never runs. Your catch block logs the error, but you won’t see that the method never reached the completion log.

Fixes:

• Add a log entry in the catch block indicating the method failed to complete:

  catch (Exception ex)
  {
      ErrorLog.createRoleLog($"Method sp_Reset_EmpAssignedCoursesByRole FAILED for Role ID {this.RoleID} Course ID {this.CourseID}: {ex.ToString()}");
      // ... existing catch logic
  }
  

• Verify that DbTransactionHelper.CommitTransaction() actually throws exceptions on failure. If it swallows errors internally, you’ll never know the commit failed.

4. Race Conditions with Instance Variables #

Your final log uses this.RoleID, this.CourseID, and sMessage—if another thread modifies these instance variables while your background thread is running, it could cause unexpected behavior (though this is more likely to corrupt log content than skip it).

Fixes:

• Copy instance variables to local variables at the start of the method to isolate them from other threads:

  public bool ResetEmployeeAssignedCoursesByRole() {
      bool bReturn = false;
      // Capture local copies of instance variables
      var localRoleID = this.RoleID;
      var localCourseID = this.CourseID;
      var localSMessage = sMessage;
      
      DbTransactionHelper dbTransactionHelper = new DbTransactionHelper();
      dbTransactionHelper.BeginTransaction();
      try {
          ErrorLog.createRoleLog($"Method sp_Reset_EmpAssignedCoursesByRole Started {localRoleID} Course ID {localCourseID} External Message {localSMessage}");
          // ... rest of your code
          
          dbTransactionHelper.CommitTransaction();
          bReturn = true;
          ErrorLog.createRoleLog($"Method sp_Reset_EmpAssignedCoursesByRole Ended {localRoleID} Course ID {localCourseID} External Message {localSMessage}");
      }
      // ... rest of method
  }
  

Step-by-Step Troubleshooting Plan #

1. Fix exception swallowing first: Update createRoleLog to log failures to the Event Log. This will immediately show if log writes are failing due to file locks or other errors.
2. Switch to IIS-safe background tasks: Replace Thread.Start() with HostingEnvironment.QueueBackgroundWorkItem (or equivalent) to eliminate thread abortion from app pool recycling.
3. Check app pool logs: Enable IIS app pool recycling logs to confirm if recycling is interrupting your background tasks.

内容的提问来源于stack exchange，提问作者summy