Search code examples
asp.netmultithreadingevent-logapplication-startaddress-operator

How to best debug the creation of unwanted threads in ASP.NET web application


After an IISRESET on my public facing webserver, the initialization of my app seems correct. That is, in the Application_Start event I launch a new "email" thread whose purpose is to sleep until the configured time, upon "waking" produce a report and email it to my administrative user(s) and go back to sleep until the configured duration elapses at which time, the report is created again and emailed out. I am currently configured to start at 1900 and produce a new report every 12 hours.

As time marches on with this production site, however, something is causing an "extra" thread to be created. This, in turn, results in a duplicate report being emailed. While the problem is benign enough, I'd like to clean this up if possible. Here's a snippet:

Public Class [Global]
Inherits System.Web.HttpApplication
Public emth As New EmailThread
Private vcomputer As String
Private eventsource As String
Private message1 As String
Public MyInstanceStart As New ThreadStart(AddressOf emth.workerThread)
Public InstanceCaller As New Thread(MyInstanceStart)

Sub Application_Start(ByVal sender As Object, ByVal e As EventArgs)
    vcomputer = System.Environment.MachineName  
    InstanceCaller.Name = "EMAILBOT"
    InstanceCaller.Start()
    UIF.WriteToLog("Application_Start: EMAILBOT instance Started")
End Sub

Examining the Application Event Log on the webserver, I can see the above message properly upon an IISRESET. This is followed by another "proper" logged event in the workerThread which tells us how long the code will sleep before the next report time. Here is a snippet from the workerThread:

Public Class EmailThread

Public Sub workerThread()
    Dim TimeToStart As Date
    Dim TimeToStart_Next As Date
    Try
        Dim Start As Integer = CInt(ConfigurationManager.AppSettings("EmailStartTime"))
        Dim iSleep As Integer = CInt(ConfigurationManager.AppSettings("RobotIntervalHours"))
        If Start < 1 Or Start > 23 Then Start = 12 
        If iSleep < 1 Or iSleep > 24 Then iSleep = 12

        TimeToStart = New Date(Now.Year, Now.Month, Now.Day, Start, 0, 0)
        Do Until TimeToStart > Now
            'We missed the start time by some amount...
            ' compute new time to start by adding RobotIntervalHours
            TimeToStart = DateAdd(DateInterval.Hour, iSleep, TimeToStart)
        Loop
        TimeToStart_Next = DateAdd(DateInterval.Hour, iSleep, TimeToStart)
        '    'Set NEXT TimeToStart for reporting
        '   Compute how long to wait now
        Dim SleepMinutes As Long
        While 1 = 1
            SleepMinutes = System.Math.Abs(DateDiff(DateInterval.Minute, Now, TimeToStart))
            strScheduledStart = FormatDateTime(TimeToStart, DateFormat.GeneralDate)
            UIF.WriteToLog("EmailThread will sleep for " & CStr(SleepMinutes) & " minutes; " & _
                           "waking at next starttime: " & strScheduledStart)
            Thread.CurrentThread.Sleep(TimeSpan.FromMinutes(SleepMinutes))
            '---------------------------------------------------------------------------------------
            '   Upon waking, resume here:
            '---------------------------------------------------------------------------------------
            TimeToStart = TimeToStart_Next
            TimeToStart_Next = DateAdd(DateInterval.Hour, iSleep, TimeToStart)
            BC.NextRobotStartTime = FormatDateTime(TimeToStart, DateFormat.GeneralDate)
            StartRobotProcess(strScheduledStart)                    'Robot reports generated
            SleepMinutes = 0           
        End While
    Catch ex As Exception
        UIF.LogException(ex, "CRITICAL: Exception in 'EmailThread.workerThread' has been logged:", 100)
    End Try
End Sub

The above code seems to work fine (like I stated, after an IISRESET, I see the one logged event from the Application_Start event followed by the log entry from my "email" thread: "EmailThread will sleep for nnn minutes...etc.". But somehow (over time) I am getting another instance of the EmailThread thus producing 2 reports instead of just one at the scheduled "wake time".

In the IIS application pool assigned to this website, I have the following settings:

- Recycle worker processes (in minutes) is UNCHECKED
- Recycle worker process (number of requests) is UNCHECKED
- Recycle worker process (at various times) is UNCHECKED / nothing specified
- [Idle timeout] Shutdown worker process after being idle for (time in minutes) is UNCHECKED

I have noticed that the Application_Start event can be entered again (in one case roughly 38 minutes after the first time) which causes my code to run again and create another [and unwanted] thread.

I would appreciate suggestions on how to tighten this up to make this symptom go away.


Solution

  • What I can think of is that in your application in IIS, you have an extra application (converting virtual folder to Application) in one of the subfolders of your website.

    ASP.NET performance counters can also help you with the number of applications and threads created. Use perfmon to monitor them.