1
votes

I have a web service hosting on a IIS 8 Application Pool. I am using log4net to log.

I was inspecting some entries in a log file and notice the thread id got change.

Here are the two log entries

<event logger="ManageStaticData" 
       timestamp="2015-08-14T03:00:00.0597938-06:00" 
       level="INFO" 
       thread="5916" 
       domain="Webservice" 
       username="IIS APPPOOL\WebServices">
  <message>Start of static data load.</message>
  <global-properties>
    <data name="log4net:HostName" value="CC" />
  </global-properties>
</event>
<event logger="ManageStaticData" 
       timestamp="2015-08-14T03:00:00.3410242-06:00" 
       level="DEBUG" 
       thread="eba102cb-8224-426e-a2b1-f4e984d4dea7" 
       domain="Webservice" 
       username="IIS APPPOOL\WebServices">
  <message>Found 1 schedule to be load</message>
  <global-properties>
    <data name="log4net:HostName" value="CC" />
  </global-properties>
</event>

The code path that shows these two log message can only come from the same method.

Notice the thread value changed from "5916" to a GUID.

After about 6 seconds, I notice that the 5916 thread start logging other web service calls. The thread with the GUID is no longer logging.

Why does the thread value change? Did log4net use a worker thread to log the entries? Or did IIS somehow switch the worker thread in the middle of the process, sound unlikely? Or is it the same thread, but got renamed?

2

2 Answers

1
votes

Each request is assigned to an available thread as it comes in. The thread id changed because you the log entries represent two separate web requests.

1
votes

Each request gets its own worker thread.

Each await of async method have chance to switching threads too during single request.

Early/late steps of ASP.Net pipeline may be swithcing threads too for singe request even if your code (which is usually the middle of pipeline steps) does not use async/await.