Bug 38715 - WebRequest timeouts after ThreadPool exhaustion
Summary: WebRequest timeouts after ThreadPool exhaustion
Status: CONFIRMED
Alias: None
Product: Runtime
Classification: Mono
Component: General (show other bugs)
Version: unspecified
Hardware: PC Mac OS
: --- normal
Target Milestone: ---
Assignee: Marek Safar
URL:
Depends on:
Blocks: 38394
  Show dependency tree
 
Reported: 2016-02-12 15:00 UTC by Alexander Köplinger [MSFT]
Modified: 2017-02-08 20:02 UTC (History)
6 users (show)

See Also:
Tags:
Is this bug a regression?: ---
Last known good build:


Attachments
Repro sample (2.07 KB, text/plain)
2016-02-12 15:00 UTC, Alexander Köplinger [MSFT]
Details

Description Alexander Köplinger [MSFT] 2016-02-12 15:00:10 UTC
Created attachment 15020 [details]
Repro sample

Based on this mailing list thread: http://lists.ximian.com/pipermail/mono-devel-list/2016-February/043510.html

Compile the attached sample code and run it. It throws "System.Net.WebException: The request timed out" errors.
On .NET the requests succeed.

According to the thread, it worked fine on Mono 3.12.

Ludovic: do you think this is indeed a ThreadPool issue or something in the System.Net implementation?

Tested on mono master/7751c2477 and mono-4.3.2-branch/9f44a62
Comment 1 Ludovic Henry 2016-02-12 17:23:39 UTC
The behaviour I observe from a ThreadPool point of view is work items are being enqueued, a worker is created/unparked right away, and execute that work item. There are also no outstanding request (request for a worker).

So AFAIK, it's more related to the System.Net stack than the theadpool.

Here is a sample output with logging enabled:

 > Mono: [0x700000def000] worker unparking, timeout? no
 > Mono: [0x700000def000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x700000ff2000] worker unparking, timeout? no
 > Mono: [0x700000ff2000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x700000ff2000] worker parking
 > 12/02/2016 17:18:05System.Net.WebException: The request timed out
 >   at System.Net.HttpWebRequest.EndGetResponse (IAsyncResult asyncResult) <0x108e8ed30 + 0x001f4> in <filename unknown>:0
 >   at System.Net.HttpWebRequest.GetResponse () <0x108e5bac0 + 0x0005a> in <filename unknown>:0
 >   at Test.MakeWebRequest (System.Object source, System.Timers.ElapsedEventArgs e) <0x10632a090 + 0x0009c> in <filename unknown>:0  Request #54 Available Threads: 0 IO  > threads: 10
 > Mono: [0x700000bec000] completed in 0x7fc1e9d01ca0
 > Mono: [0x700000bec000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x700000bec000] worker parking
 > Mono: [0x7000011f5000] worker unparking, timeout? no
 > Mono: [0x7000011f5000] worker parking
 > Mono: [0x7000007e6000] worker unparking, timeout? no
 > Mono: [0x7000007e6000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x7000017fe000] worker unparking, timeout? no
 > Mono: [0x7000017fe000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x7000017fe000] worker parking
 > 12/02/2016 17:18:05System.Net.WebException: The request timed out
 >   at System.Net.HttpWebRequest.EndGetResponse (IAsyncResult asyncResult) <0x108e8ed30 + 0x001f4> in <filename unknown>:0
 >   at System.Net.HttpWebRequest.GetResponse () <0x108e5bac0 + 0x0005a> in <filename unknown>:0
 >   at Test.MakeWebRequest (System.Object source, System.Timers.ElapsedEventArgs e) <0x10632a090 + 0x0009c> in <filename unknown>:0  Request #55 Available Threads: 0 IO  > threads: 10
 > Mono: [0x700000def000] completed in 0x7fc1e9d01ca0
 > Mono: [0x700000def000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x700000def000] worker parking
 > Mono: [0x7000009e9000] worker unparking, timeout? no
 > Mono: [0x7000009e9000] worker parking
 > Mono: [0x7000013f8000] worker unparking, timeout? no
 > Mono: [0x7000013f8000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x7000015fb000] worker unparking, timeout? no
 > Mono: [0x7000015fb000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x7000015fb000] worker parking
 > 12/02/2016 17:18:06System.Net.WebException: The request timed out
 >   at System.Net.HttpWebRequest.EndGetResponse (IAsyncResult asyncResult) <0x108e8ed30 + 0x001f4> in <filename unknown>:0
 >   at System.Net.HttpWebRequest.GetResponse () <0x108e5bac0 + 0x0005a> in <filename unknown>:0
 >   at Test.MakeWebRequest (System.Object source, System.Timers.ElapsedEventArgs e) <0x10632a090 + 0x0009c> in <filename unknown>:0  Request #56 Available Threads: 0 IO  > threads: 10
 > Mono: [0x7000007e6000] completed in 0x7fc1e9d01ca0
 > Mono: [0x7000007e6000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x7000007e6000] worker parking
 > Mono: [0x700001a01000] worker unparking, timeout? no
 > Mono: [0x700001a01000] worker parking
 > Mono: [0x700000ff2000] worker unparking, timeout? no
 > Mono: [0x700000ff2000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x700000bec000] worker unparking, timeout? no
 > Mono: [0x700000bec000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x700000bec000] worker parking
 > 12/02/2016 17:18:06System.Net.WebException: The request timed out
 >   at System.Net.HttpWebRequest.EndGetResponse (IAsyncResult asyncResult) <0x108e8ed30 + 0x001f4> in <filename unknown>:0
 >   at System.Net.HttpWebRequest.GetResponse () <0x108e5bac0 + 0x0005a> in <filename unknown>:0
 >   at Test.MakeWebRequest (System.Object source, System.Timers.ElapsedEventArgs e) <0x10632a090 + 0x0009c> in <filename unknown>:0  Request #57 Available Threads: 0 IO  > threads: 10
 > Mono: [0x7000013f8000] completed in 0x7fc1e9d01ca0
 > Mono: [0x7000013f8000] worker running in 0x7fc1e9d01ca0, outstanding_request = 0
 > Mono: [0x7000013f8000] worker parking
 > Mono: [0x7000011f5000] worker unparking, timeout? no
 > Mono: [0x7000011f5000] worker parking
Comment 2 Andres G. Aragoneses 2016-02-12 17:28:24 UTC
> So AFAIK, it's more related to the System.Net stack than the theadpool.

Sys.net has changed substantially since 3.12 too, right?
Comment 3 Seif Attar 2016-02-12 21:01:52 UTC
Interesting, I guess it could be System.Net. Don't know if it helps but what I noticed is that the issue only happens if requests are made while ThreadPool is busy and has some work queued. If requests are started after tasks completed, issue doesn't manifest.
Comment 4 mike h 2016-02-15 14:07:00 UTC
we ran the test app and see the same issue with mono 3.12 on OpenSUSE 13.2 (kernel 3.16.7, libc 2.19).
Comment 5 Seif Attar 2016-02-15 15:51:12 UTC
Mike, I couldn't reproduce with libc 2.21, we had similar symptoms before caused by https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=722075 (which affects 2.19), I would look in gdb and see where the threads are stuck.

Note You need to log in before you can comment on or make changes to this bug.