Bug 38577 - Many "Hill Climbing, change max number of threads" messages in Android application output when Inspector installed
Summary: Many "Hill Climbing, change max number of threads" messages in Android applic...
Status: RESOLVED NOT_ON_ROADMAP
Alias: None
Product: Workbooks & Inspector
Classification: Xamarin
Component: Agent: Android ()
Version: 0.5.0
Hardware: Macintosh Mac OS
: --- normal
Target Milestone: ---
Assignee: Sandy Armstrong [MSFT]
URL:
Depends on:
Blocks:
 
Reported: 2016-02-09 14:52 UTC by Nate Cook
Modified: 2016-05-26 13:43 UTC (History)
5 users (show)

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


Attachments
Screenshot of Visual Studio with debug output (273.39 KB, image/png)
2016-03-16 08:35 UTC, Michael Rumpler
Details
XamarinVS logs from the last week (274.46 KB, application/x-zip-compressed)
2016-04-20 13:14 UTC, Michael Rumpler
Details
the text from my output window while the app hung (212.51 KB, text/plain)
2016-04-20 13:23 UTC, Michael Rumpler
Details


Notice (2018-05-24): bugzilla.xamarin.com is now in read-only mode.

Please join us on Visual Studio Developer Community and in the Xamarin and Mono organizations on GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs, copy them to the new locations as needed for follow-up, and add the new items under Related Links.

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.


Please create a new report on Developer Community with your current version information, steps to reproduce, and relevant error messages or log files if you are hitting an issue that looks similar to this resolved bug and you do not yet see a matching new report.

Related Links:
Status:
RESOLVED NOT_ON_ROADMAP

Description Nate Cook 2016-02-09 14:52:07 UTC
I get output like the following in the application output window when the Xamarin Inspector is installed. When the Inspector is disabled I get normal application output. Just wanted to let you guys know in case you have a leak somewhere.

Thread finished:  #12
[Mono] [0xaeffe980] hill climbing, change max number of threads 3
[Mono] [0xaeffe980] hill climbing, change max number of threads 2
Thread finished: <Thread Pool> #4
Thread started: <Thread Pool> #13
[Mono] [0xaec9a700] hill climbing, change max number of threads 3
[Mono] [0x9773c100] worker finishing
Thread finished: <Thread Pool> #11
[Mono] [0xaec9a700] hill climbing, change max number of threads 2
[Mono] [0xaec99d00] hill climbing, change max number of threads 3
Thread finished: <Thread Pool> #13
Thread started: <Thread Pool> #14
[Mono] [0xaec99f80] hill climbing, change max number of threads 4
[Mono] [0xaec99f80] hill climbing, change max number of threads 5
[Mono] [0xaec9a700] hill climbing, change max number of threads 2
[Mono] [0xaec9a700] hill climbing, change max number of threads 3
Thread finished: <Thread Pool> #14
Thread started: <Thread Pool> #15
[Mono] [0xaeffe980] hill climbing, change max number of threads 2
[Mono] [0xaec9a200] hill climbing, change max number of threads 3
[Mono] [0xaec9a200] hill climbing, change max number of threads 4
Thread started: <Thread Pool> #16
[Mono] [0x96f08580] worker starting
[Mono] [0xaec9a700] hill climbing, change max number of threads 2
[Mono] [0x96f08580] hill climbing, change max number of threads 3

I left the Android app debugging all night and by the end of the night I was getting messages like this:

[Mono] [0x95321000] hill climbing, change max number of threads 126
Thread finished: <Thread Pool> #872
Thread started: <Thread Pool> #873
Thread finished: <Thread Pool> #873
Thread started: <Thread Pool> #874
Thread finished: <Thread Pool> #874
Thread started: <Thread Pool> #875
Thread finished: <Thread Pool> #875
Thread started: <Thread Pool> #876
Thread finished: <Thread Pool> #876
Thread started: <Thread Pool> #877
Thread finished: <Thread Pool> #877
Thread started: <Thread Pool> #878
Thread finished: <Thread Pool> #878
Thread started: <Thread Pool> #879
Thread finished: <Thread Pool> #879
Thread started: <Thread Pool> #880
Thread finished: <Thread Pool> #880
Thread started: <Thread Pool> #881
[Mono] [0x93414b00] hill climbing, change max number of threads 127
Thread finished: <Thread Pool> #881
Thread started: <Thread Pool> #882
Thread finished: <Thread Pool> #882
Thread started: <Thread Pool> #883
[Mono] [0x97067c80] hill climbing, change max number of threads 147
Thread finished: <Thread Pool> #883
Thread started: <Thread Pool> #884
Thread finished: <Thread Pool> #884
Thread started: <Thread Pool> #885
Thread finished: <Thread Pool> #885
Thread started: <Thread Pool> #886
Thread finished: <Thread Pool> #886
Thread started: <Thread Pool> #887
Thread finished: <Thread Pool> #887
Thread started: <Thread Pool> #888
[Mono] [0x95320880] hill climbing, change max number of threads 148
Thread finished: <Thread Pool> #888
Thread started: <Thread Pool> #889
Thread finished: <Thread Pool> #889
Thread started: <Thread Pool> #890
Thread finished: <Thread Pool> #890
Thread started: <Thread Pool> #891
Thread finished: <Thread Pool> #891
Thread started: <Thread Pool> #892
Thread finished: <Thread Pool> #892
Thread started: <Thread Pool> #893
[Mono] [0x9531f200] hill climbing, change max number of threads 149
Thread started: <Thread Pool> #894
[Mono] [0x97067f00] worker starting
Thread finished: <Thread Pool> #893
Thread started: <Thread Pool> #895
[Mono] [0x97067c80] worker finishing
Thread finished: <Thread Pool> #860
Thread finished: <Thread Pool> #895
Thread started: <Thread Pool> #896
Thread finished: <Thread Pool> #896
Thread started: <Thread Pool> #897
Thread finished: <Thread Pool> #897
Thread started: <Thread Pool> #898
Thread finished: <Thread Pool> #898
Thread started: <Thread Pool> #899
Thread finished: <Thread Pool> #899
Thread started: <Thread Pool> #900
Thread finished: <Thread Pool> #900
Thread started: <Thread Pool> #901
Thread finished: <Thread Pool> #901
Thread started: <Thread Pool> #902
Thread finished: <Thread Pool> #902
Thread started: <Thread Pool> #903
[Mono] [0x9531f700] hill climbing, change max number of threads 150
Thread finished: <Thread Pool> #903
Thread started: <Thread Pool> #904
Thread finished: <Thread Pool> #904
Thread started: <Thread Pool> #905
Thread finished: <Thread Pool> #905
Thread started: <Thread Pool> #906
Thread finished: <Thread Pool> #906
Thread started: <Thread Pool> #907
Thread finished: <Thread Pool> #907
Thread started: <Thread Pool> #908
Thread finished: <Thread Pool> #908
Thread started: <Thread Pool> #909
Thread finished: <Thread Pool> #909
Thread started: <Thread Pool> #910
Thread finished: <Thread Pool> #910
Thread started: <Thread Pool> #911
Thread finished: <Thread Pool> #911
Thread started: <Thread Pool> #912
Thread finished: <Thread Pool> #912
Thread started: <Thread Pool> #913
Thread finished: <Thread Pool> #913
Thread started: <Thread Pool> #914
Thread finished: <Thread Pool> #914
Thread started: <Thread Pool> #915
Thread finished: <Thread Pool> #915
Thread started: <Thread Pool> #916
[Mono] [0x95320600] hill climbing, change max number of threads 151
Thread finished: <Thread Pool> #916
Thread started: <Thread Pool> #917
[Mono] [0x97067f00] hill climbing, change max number of threads 131
[Mono] [0x95320b00] hill climbing, change max number of threads 132
Thread finished: <Thread Pool> #917
Thread started: <Thread Pool> #918
Thread finished: <Thread Pool> #918
Thread started: <Thread Pool> #919
[Mono] [0x95320d80] hill climbing, change max number of threads 133
Thread finished: <Thread Pool> #919
Thread started: <Thread Pool> #920
Thread finished: <Thread Pool> #920
Thread started: <Thread Pool> #921
Thread finished: <Thread Pool> #921
Thread started: <Thread Pool> #922
Thread finished: <Thread Pool> #922
Thread started: <Thread Pool> #923
Thread finished: <Thread Pool> #923
Thread started: <Thread Pool> #924
Thread finished: <Thread Pool> #924
Thread started: <Thread Pool> #925
Thread finished: <Thread Pool> #925
Thread started: <Thread Pool> #926
Thread finished: <Thread Pool> #926
Thread started: <Thread Pool> #927
Thread finished: <Thread Pool> #927
Thread started: <Thread Pool> #928
Thread finished: <Thread Pool> #928
Thread started: <Thread Pool> #929
Thread finished: <Thread Pool> #929
Thread started: <Thread Pool> #930
[Mono] [0x9531f980] hill climbing, change max number of threads 134
Thread finished: <Thread Pool> #930
Thread started: <Thread Pool> #931
Thread finished: <Thread Pool> #931
Thread started: <Thread Pool> #932
Thread finished: <Thread Pool> #932
Thread started: <Thread Pool> #933
Thread finished: <Thread Pool> #933
Thread started: <Thread Pool> #934
Thread finished: <Thread Pool> #934
Thread started: <Thread Pool> #935
Thread finished: <Thread Pool> #935
Thread started: <Thread Pool> #936
Thread finished: <Thread Pool> #936
Thread started: <Thread Pool> #937
Thread finished: <Thread Pool> #937
Thread started: <Thread Pool> #938
Thread finished: <Thread Pool> #938
Thread started: <Thread Pool> #939

Again, not affecting our app really but just wanted to make you guys aware.

Xamarin Studio
Version 5.10.2 (build 56)
Installation UUID: ef4eb426-7861-41a8-860d-6c0e3c8baa5f
Runtime:
	Mono 4.2.2 (explicit/996df3c)
	GTK+ 2.24.23 (Raleigh theme)

	Package version: 402020030

Xamarin.Profiler
Not Installed

Xamarin.Android
Version: 6.0.1.10 (Business Edition)
Android SDK: /Users/ncook/Library/Developer/Xamarin/android-sdk-macosx
	Supported Android versions:
		4.0.3 (API level 15)
		4.4   (API level 19)
		5.0   (API level 21)

SDK Tools Version: 24.4.1
SDK Platform Tools Version: 23.0.1
SDK Build Tools Version: 23.0.1

Java SDK: /usr
java version "1.7.0_71"
Java(TM) SE Runtime Environment (build 1.7.0_71-b14)
Java HotSpot(TM) 64-Bit Server VM (build 24.71-b01, mixed mode)

Xamarin Android Player
Version: 0.6.2
Location: /Applications/Xamarin Android Player.app

Apple Developer Tools
Xcode 7.2.1 (9548.1)
Build 7C1002

Xamarin.Mac
Version: 2.4.1.6 (Starter Edition)

Xamarin.iOS
Version: 9.4.1.25 (Business Edition)
Hash: 962a050
Branch: master
Build date: 2016-01-29 16:59:11-0500

Xamarin Inspector
Version: 0.5.0.0
Hash: 45b35bb
Branch: master
Build date: Thu Jan 14 18:53:32 UTC 2016

Build Information
Release ID: 510020056
Git revision: bb74ff467c62ded42b7b7ac7fdd2edc60f8647b0
Build date: 2016-01-26 16:24:41-05
Xamarin addins: 8b797d7ba24d5abab226c2cf9fda77f666263f1b
Build lane: monodevelop-lion-cycle6-c6sr1

Operating System
Mac OS X 10.11.3
Darwin Nate-Insightly-MacBook-Pro.local 15.3.0 Darwin Kernel Version 15.3.0
    Thu Dec 10 18:40:58 PST 2015
    root:xnu-3248.30.4~1/RELEASE_X86_64 x86_64
Comment 1 Sandy Armstrong [MSFT] 2016-02-09 15:17:25 UTC
Thanks for the heads up, we'll take a look.
Comment 2 Sandy Armstrong [MSFT] 2016-02-09 15:28:04 UTC
To be clear, you're not actually launching the Inspector for this app, right? You're just debugging it while the Inspector addin is installed/enabled?
Comment 3 Nate Cook 2016-02-09 15:29:16 UTC
Correct, I am not launching the Inspector.
Comment 4 Sandy Armstrong [MSFT] 2016-02-09 15:32:49 UTC
This should be harmless, then. All we're doing is running a repeating timer to periodically call a method that our addin hooks into if you do decide to inspect.

So, not a leak, but we'll see about making it less noisy.
Comment 5 Nate Cook 2016-02-09 15:34:09 UTC
"change max number of threads 151" doesn't indicate a leak to you? I can't imagine why the inspector would need 151 threads, or why the number of threads that it would need would increase over time (especially since the app was not being used all night).
Comment 6 Sandy Armstrong [MSFT] 2016-02-09 16:17:28 UTC
Yes, I misspoke, it does appear to be leaking threads.
Comment 7 Sandy Armstrong [MSFT] 2016-02-09 17:19:00 UTC
I have pretty much the same install setup as you, and I see the non-leaky output I'd expect from posting to the Android mainloop's SynchronizationContext every second (which is what we do):

[Mono] [0xb96ba098] hill climbing, change max number of threads 2
[Mono] [0xb96ba098] hill climbing, change max number of threads 1
[Mono] [0xb96ba098] hill climbing, change max number of threads 2
[Mono] [0xb96ba098] hill climbing, change max number of threads 1
[Mono] [0xb96ba098] hill climbing, change max number of threads 2

(this over and over again)

I'm not yet sure what's causing your threadpool to hang on to these threads.

Regardless, I'll look at some alternative that doesn't cause threadpool spam.
Comment 8 Michael Rumpler 2016-03-16 08:31:23 UTC
I'm not sure if this is related, but I also get weird thread output in my debug window and my app needs very long at the start until it responds. I uninstalled Inspector after I saw this bug, but that didn't change anything.

I have a Xamarin.Forms app which displays a simple ContentPage on start and it starts a background thread which loads the previously opened files. Once this is finished, it replaces the MainPage with a MasterDetailPage. I see in the output window, that my background thread loaded everything and is long finished, the Toolbar for both Master and Detail are displayed, but the Master and Detail page contents are still not there while I have tons of hill climbing and GC messages.

That strange behavior started yesterday and I also installed Inspector yesterday, but I'm not 100% sure if it's related because I already uninstalled it.
Comment 9 Michael Rumpler 2016-03-16 08:35:09 UTC
Created attachment 15423 [details]
Screenshot of Visual Studio with debug output

I reached a new record with a

    hill climbing, change max number of threads 200

message. It doesn't seem as my app comes back to live again. All my own background tasks are long finished.
Comment 10 Michael Rumpler 2016-04-14 11:51:44 UTC
I was suffering these problems for the last months. I had to wait minutes until my app got responsive.

Yesterday I tried to install a new Xamarin VS release and it failed. After that, Xamarin was not available anymore in VS. So I installed VS Update 2 including Xamarin.

Now the problems are gone. No more extensive hill climbing and GC messages anymore. The app behaves as it should.

Apparently the uninstall of Inspector did not work cleanly, or something else was broken. Whatever it was, it got fixed with the fresh install.
Comment 11 Michael Rumpler 2016-04-20 13:09:25 UTC
The VS Update 2 installed XamarinVS 4.0.3.214.
I installed XamarinVS 4.1.0.313 today and the strange behavior from before came back. I did not reinstall the Inspector so I doubt that my problem is related to it.

The app hangs again with tons of these messages:

04-20 14:38:15.795 D/Mono    (  817): [0xba129f50] hill climbing, change max number of threads 69
04-20 14:38:16.640 I/art     (  817): Explicit concurrent mark sweep GC freed 3887(242KB) AllocSpace objects, 1(312KB) LOS objects, 39% free, 8MB/14MB, paused 561us total 16.424ms
04-20 14:38:16.645 D/Mono    (  817): GC_OLD_BRIDGE num-objects 626 num_hash_entries 32002 sccs size 18227 init 0.00ms df1 82.54ms sort 14.11ms dfs2 541.01ms setup-cb 2.91ms free-data 149.39ms links 125922/125922/4118634/234 dfs passes 158550/144149
04-20 14:38:16.645 D/Mono    (  817): GC_MINOR: (Nursery full) pause 87.57ms, total 92.66ms, bridge 0.00ms promoted 144K major 3888K los 884K
Thread started: <Thread Pool> #19
Thread started: <Thread Pool> #20
Thread started: <Thread Pool> #21
Thread started: <Thread Pool> #22
...

I do NOT do any background work at this point of time.
Comment 12 Michael Rumpler 2016-04-20 13:14:00 UTC
Created attachment 15778 [details]
XamarinVS logs from the last week

These are the logs from the last week. It shows a broken, fixed and at the end broken functionality again.
Comment 13 Michael Rumpler 2016-04-20 13:23:38 UTC
Created attachment 15779 [details]
the text from my output window while the app hung

This is my output window from when I tried to run my app, but it hang.

It is a Xamarin.Forms app which first shows a NavigationPage with just one ContentPage. As soon as all the previously loaded files are reloaded, it sets the MainPage to a new MasterDetailPage (Split) with both Master and Detail being NavigationPages. When the app hangs, then the tablet only shows the navigation area of that UI. I.e. Titles and ToolbarItems are there, but the rest of the Master and Detail pages are empty.
The app writes "UI.RefreshMainPage[174]: done" to the log when its background work is finished and the UI should have been refreshed. In this case that was at 14:38:15.517. I gave it until 14:45:26.095, but it never came back.
Comment 14 Michael Rumpler 2016-04-20 13:33:43 UTC
This may also be related to https://bugzilla.xamarin.com/show_bug.cgi?id=38982.

Both Ronald and Nate report similar messages in the output window. I have the same messages, but additionally many GC messages which (I guess) come from the many threads started and finishing.
Comment 15 Sandy Armstrong [MSFT] 2016-04-20 13:54:59 UTC
Michael, what you're seeing is definitely not related to the Inspector or this bug (since the Inspector is not installed).

You should follow up in bug #38982 or open a new one.
Comment 16 Aaron Bockover [MSFT] 2016-05-26 13:32:15 UTC
Closing this based on Sandy's Comment #15.
Comment 17 Aaron Bockover [MSFT] 2016-05-26 13:42:02 UTC
Reopening. Apologies, I misinterpreted what Sandy was saying.
Comment 18 Sandy Armstrong [MSFT] 2016-05-26 13:43:24 UTC
I've never been able to reproduce the level of threadpool activity that was originally reported.

When this bug was initially filed I looked into some approaches to reducing even simple threadpool spam, but there was nothing really satisfactory.

Keeping the bug as resolved since I have no intention of revisiting unless more customers run into the threadpool leakage (please reopen if this bug still applies to you).