Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Mac Catalyst: GC doesn't collect object with finalizers #47407

Closed
rolfbjarne opened this issue Jan 25, 2021 · 5 comments
Closed

Mac Catalyst: GC doesn't collect object with finalizers #47407

rolfbjarne opened this issue Jan 25, 2021 · 5 comments
Labels
area-GC-mono untriaged New issue has not been triaged by the area owner

Comments

@rolfbjarne
Copy link
Member

Repro:

git clone https://github.com/rolfbjarne/xamarin-macios
cd xamarin-macios
git checkout mac-catalyst-debug-gc
./configure --enable-dotnet
make reset
make all -j8
make install -j8
make install-system
make test-mac-catalyst-gc

This will build xamarin-macios, install it locally, build a test application and run it.

The test code is very simple, it just creates objects in a loop, and runs the GC once in a while:

https://github.com/rolfbjarne/xamarin-macios/blob/99d7b97fc2b6bbaa72f05cc407fcad603e8955d8/tests/common/TestProjects/MyCatalystApp/Main.cs#L17-L33

GC log info has been enabled, and shows that the memory used grows:

2021-01-25 15:41:05.670 MyCatalystApp[66296:1549180] Counter: 10000
2021-01-25 15:41:05.673 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 2.22ms, stw 2.41ms los size: 1024K in use: 29K
2021-01-25 15:41:05.673 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1296K in use: 552K
2021-01-25 15:41:05.685 MyCatalystApp[66296:1549180] Counter: 20000
2021-01-25 15:41:05.687 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 1.52ms, stw 1.74ms los size: 1024K in use: 29K
2021-01-25 15:41:05.687 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1456K in use: 702K
2021-01-25 15:41:05.699 MyCatalystApp[66296:1549180] Counter: 30000
2021-01-25 15:41:05.701 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 1.44ms, stw 1.50ms los size: 1024K in use: 29K
2021-01-25 15:41:05.701 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1616K in use: 849K
[...]
2021-01-25 15:41:06.042 MyCatalystApp[66296:1549180] Counter: 260000
2021-01-25 15:41:06.045 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 2.71ms, stw 2.90ms los size: 1024K in use: 40K
2021-01-25 15:41:06.045 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 5504K in use: 4329K
[...]
2021-01-25 15:41:14.997 MyCatalystApp[66296:1549180] Counter: 3730000
2021-01-25 15:41:15.020 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 22.04ms, stw 23.21ms los size: 1024K in use: 40K
2021-01-25 15:41:15.020 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 60752K in use: 51921K
[...]
2021-01-25 15:41:53.388 MyCatalystApp[66296:1549180] Counter: 10580000
2021-01-25 15:41:53.453 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 61.60ms, stw 64.55ms los size: 1024K in use: 40K
2021-01-25 15:41:53.453 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 169808K in use: 147206K
[..]
2021-01-25 15:50:35.013 MyCatalystApp[66296:1549180] Counter: 14900000
2021-01-25 15:50:35.270 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 103.58ms, stw 257.80ms los size: 1024K in use: 40K
2021-01-25 15:50:35.271 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 238576K in use: 209697K
2021-01-25 15:50:36.525 MyCatalystApp[66296:1549180] Counter: 14910000

Changing the test case to use the WithoutDestructor class instead makes the memory usage stay constant.
@dotnet-issue-labeler dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Jan 25, 2021
@dotnet-issue-labeler
Copy link

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

@rolfbjarne rolfbjarne mentioned this issue Jan 25, 2021
Closed
2 tasks
@ghost
Copy link

ghost commented Jan 26, 2021

Tagging subscribers to this area: @CoffeeFlux
See info in area-owners.md if you want to be subscribed.

Issue Details

Repro:

git clone https://github.com/rolfbjarne/xamarin-macios
cd xamarin-macios
git checkout mac-catalyst-debug-gc
./configure --enable-dotnet
make reset
make all -j8
make install -j8
make install-system
make test-mac-catalyst-gc

This will build xamarin-macios, install it locally, build a test application and run it.

The test code is very simple, it just creates objects in a loop, and runs the GC once in a while:

https://github.com/rolfbjarne/xamarin-macios/blob/99d7b97fc2b6bbaa72f05cc407fcad603e8955d8/tests/common/TestProjects/MyCatalystApp/Main.cs#L17-L33

GC log info has been enabled, and shows that the memory used grows:

2021-01-25 15:41:05.670 MyCatalystApp[66296:1549180] Counter: 10000
2021-01-25 15:41:05.673 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 2.22ms, stw 2.41ms los size: 1024K in use: 29K
2021-01-25 15:41:05.673 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1296K in use: 552K
2021-01-25 15:41:05.685 MyCatalystApp[66296:1549180] Counter: 20000
2021-01-25 15:41:05.687 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 1.52ms, stw 1.74ms los size: 1024K in use: 29K
2021-01-25 15:41:05.687 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1456K in use: 702K
2021-01-25 15:41:05.699 MyCatalystApp[66296:1549180] Counter: 30000
2021-01-25 15:41:05.701 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 1.44ms, stw 1.50ms los size: 1024K in use: 29K
2021-01-25 15:41:05.701 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1616K in use: 849K
[...]
2021-01-25 15:41:06.042 MyCatalystApp[66296:1549180] Counter: 260000
2021-01-25 15:41:06.045 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 2.71ms, stw 2.90ms los size: 1024K in use: 40K
2021-01-25 15:41:06.045 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 5504K in use: 4329K
[...]
2021-01-25 15:41:14.997 MyCatalystApp[66296:1549180] Counter: 3730000
2021-01-25 15:41:15.020 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 22.04ms, stw 23.21ms los size: 1024K in use: 40K
2021-01-25 15:41:15.020 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 60752K in use: 51921K
[...]
2021-01-25 15:41:53.388 MyCatalystApp[66296:1549180] Counter: 10580000
2021-01-25 15:41:53.453 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 61.60ms, stw 64.55ms los size: 1024K in use: 40K
2021-01-25 15:41:53.453 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 169808K in use: 147206K
[..]
2021-01-25 15:50:35.013 MyCatalystApp[66296:1549180] Counter: 14900000
2021-01-25 15:50:35.270 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 103.58ms, stw 257.80ms los size: 1024K in use: 40K
2021-01-25 15:50:35.271 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 238576K in use: 209697K
2021-01-25 15:50:36.525 MyCatalystApp[66296:1549180] Counter: 14910000

Changing the test case to use the WithoutDestructor class instead makes the memory usage stay constant.

Author: rolfbjarne
Assignees: -
Labels:

area-VM-meta-mono, untriaged
Milestone: -

@ghost
Copy link

ghost commented Jan 26, 2021

Tagging subscribers to this area: @BrzVlad
See info in area-owners.md if you want to be subscribed.

Issue Details

Repro:

git clone https://github.com/rolfbjarne/xamarin-macios
cd xamarin-macios
git checkout mac-catalyst-debug-gc
./configure --enable-dotnet
make reset
make all -j8
make install -j8
make install-system
make test-mac-catalyst-gc

This will build xamarin-macios, install it locally, build a test application and run it.

The test code is very simple, it just creates objects in a loop, and runs the GC once in a while:

https://github.com/rolfbjarne/xamarin-macios/blob/99d7b97fc2b6bbaa72f05cc407fcad603e8955d8/tests/common/TestProjects/MyCatalystApp/Main.cs#L17-L33

GC log info has been enabled, and shows that the memory used grows:

2021-01-25 15:41:05.670 MyCatalystApp[66296:1549180] Counter: 10000
2021-01-25 15:41:05.673 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 2.22ms, stw 2.41ms los size: 1024K in use: 29K
2021-01-25 15:41:05.673 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1296K in use: 552K
2021-01-25 15:41:05.685 MyCatalystApp[66296:1549180] Counter: 20000
2021-01-25 15:41:05.687 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 1.52ms, stw 1.74ms los size: 1024K in use: 29K
2021-01-25 15:41:05.687 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1456K in use: 702K
2021-01-25 15:41:05.699 MyCatalystApp[66296:1549180] Counter: 30000
2021-01-25 15:41:05.701 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 1.44ms, stw 1.50ms los size: 1024K in use: 29K
2021-01-25 15:41:05.701 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 1616K in use: 849K
[...]
2021-01-25 15:41:06.042 MyCatalystApp[66296:1549180] Counter: 260000
2021-01-25 15:41:06.045 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 2.71ms, stw 2.90ms los size: 1024K in use: 40K
2021-01-25 15:41:06.045 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 5504K in use: 4329K
[...]
2021-01-25 15:41:14.997 MyCatalystApp[66296:1549180] Counter: 3730000
2021-01-25 15:41:15.020 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 22.04ms, stw 23.21ms los size: 1024K in use: 40K
2021-01-25 15:41:15.020 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 60752K in use: 51921K
[...]
2021-01-25 15:41:53.388 MyCatalystApp[66296:1549180] Counter: 10580000
2021-01-25 15:41:53.453 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 61.60ms, stw 64.55ms los size: 1024K in use: 40K
2021-01-25 15:41:53.453 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 169808K in use: 147206K
[..]
2021-01-25 15:50:35.013 MyCatalystApp[66296:1549180] Counter: 14900000
2021-01-25 15:50:35.270 MyCatalystApp[66296:1549180] info: GC_MAJOR: (user request) time 103.58ms, stw 257.80ms los size: 1024K in use: 40K
2021-01-25 15:50:35.271 MyCatalystApp[66296:1549180] info: GC_MAJOR_SWEEP: major size: 238576K in use: 209697K
2021-01-25 15:50:36.525 MyCatalystApp[66296:1549180] Counter: 14910000

Changing the test case to use the WithoutDestructor class instead makes the memory usage stay constant.

Author: rolfbjarne
Assignees: -
Labels:

area-GC-mono, untriaged
Milestone: -

@rolfbjarne rolfbjarne mentioned this issue Feb 9, 2021
Closed
61 tasks
@rolfbjarne
Copy link
Member Author

This seems to be working again now.

@BrzVlad
Copy link
Member

BrzVlad commented Jun 2, 2021

I'm not convinced this was ever a bug. Maybe there was contention with the finalizer thread, which wasn't able to process its queue at the same rate new finalizers were added.

@ghost ghost locked as resolved and limited conversation to collaborators Jul 2, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
area-GC-mono untriaged New issue has not been triaged by the area owner
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rolfbjarne @CoffeeFlux @BrzVlad @jeffschwMSFT