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.

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

Possible SerialPort memory leak on Raspbian (all Unix?) #55146

Closed
dseeg opened this issue Jul 4, 2021 · 8 comments · Fixed by #68014
Closed

Possible SerialPort memory leak on Raspbian (all Unix?) #55146

dseeg opened this issue Jul 4, 2021 · 8 comments · Fixed by #68014
Labels
Milestone

Comments

@dseeg
Copy link

dseeg commented Jul 4, 2021

Description

When using SerialPort.Read(byte[] buffer, int offset, int count) and a TimeoutException occures, the reference for the byte[] buffer used is not released by the underlying SerialStream used by SerialPort.

Sample repo: https://github.com/dseeg/SerialPortMemoryLeak

Application runs though 20000 iterations of trying to read from a SerialPort and timing out each time.

Configuration

  • .NET Version: .NET 5.0.301
  • OS: Raspbian 9.13 stretch
  • Architecture: ARM

Regression?

Unknown

Data

dotnet-counters

Press p to pause, r to resume, q to quit.
    Status: Running

[System.Runtime]
    % Time in GC since last GC (%)                                 0
    Allocation Rate (B / 1 sec)                               33,260
    CPU Usage (%)                                                  1
    Exception Count (Count / 1 sec)                                0
    GC Fragmentation (%)                                           7.642
    GC Heap Size (MB)                                             24
    Gen 0 GC Count (Count / 1 sec)                                 1
    Gen 0 Size (B)                                             9,884
    Gen 1 GC Count (Count / 1 sec)                                 0
    Gen 1 Size (B)                                           485,444
    Gen 2 GC Count (Count / 1 sec)                                 0
    Gen 2 Size (B)                                        25,744,976
    IL Bytes Jitted (B)                                       75,380
    LOH Size (B)                                             131,120
    Monitor Lock Contention Count (Count / 1 sec)                  0
    Number of Active Timers                                        0
    Number of Assemblies Loaded                                   19
    Number of Methods Jitted                                     735
    POH (Pinned Object Heap) Size (B)                         20,016
    ThreadPool Completed Work Item Count (Count / 1 sec)           0
    ThreadPool Queue Length                                        0
    ThreadPool Thread Count                                        0
    Working Set (MB)                                              84

dumpheap -stat

...
6604d32c       11       262276 System.Collections.Concurrent.ConcurrentQueueSegment`1+Slot[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]][]
6a2c3248    20000       560000 System.IO.Ports.SerialStream+SerialStreamIORequest
6601239c    20000       800000 System.Threading.Tasks.Task`1[[System.Int32, System.Private.CoreLib]]
66014c18    20000       880000 System.Threading.Tasks.Task+ContingentProperties
66012008    20002       880088 System.Threading.CancellationTokenSource
011b9e40    31952      2024484      Free
6a2b700c    20025     20732431 System.Byte[]
Total 135477 objects

gcroot inspection

...
53bf10f4 6a2b700c     1036
53bf157c 6a2b700c     1036
53bf1a04 6a2b700c     1036
53bf1e8c 6a2b700c     1036
53bf2314 6a2b700c     1036
53bf27a8 6a2b700c     1036
53bf2c3c 6a2b700c     1036
53bf30c4 6a2b700c     1036
53bf354c 6a2b700c     1036
53bf39f8 6a2b700c     1036
53bf3eb4 6a2b700c     1036
53bf5708 6a2b700c     1036
53bf6a70 6a2b700c     1036
53bfa4a0 6a2b700c     1036
53bfce58 6a2b700c     1036
53c01688 6a2b700c     1036
53c08bcc 6a2b700c     1036

Statistics:
      MT    Count    TotalSize Class Name
6a2b700c    20025     20732431 System.Byte[]
Total 20025 objects

> gcroot 53bfa4a0
Found 0 unique roots (run 'gcroot -all' to see all roots).
> gcroot 53bf30c4
Thread 75d4:
    7E9016F0 6A215A8C SerialPortMemoryLeak.Program.Main(System.String[]) [C:\Users\Dillon\source\repos\SerialPortMemoryLeak\SerialPortMemoryLeak\Program.cs @ 55]
        r11-44: 7e90171c
            ->  62F08D38 System.IO.Ports.SerialPort
            ->  62F09288 System.IO.Ports.SerialStream
            ->  62F09310 System.Collections.Concurrent.ConcurrentQueue`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  53766868 System.Collections.Concurrent.ConcurrentQueueSegment`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  63F00020 System.Collections.Concurrent.ConcurrentQueueSegment`1+Slot[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]][]
            ->  53BF3508 System.IO.Ports.SerialStream+SerialStreamIORequest
            ->  53BF30C4 System.Byte[]

Found 1 unique roots (run 'gcroot -all' to see all roots).
> gcroot 53bf1e8c
Thread 75d4:
    7E9016F0 6A215A8C SerialPortMemoryLeak.Program.Main(System.String[]) [C:\Users\Dillon\source\repos\SerialPortMemoryLeak\SerialPortMemoryLeak\Program.cs @ 55]
        r11-44: 7e90171c
            ->  62F08D38 System.IO.Ports.SerialPort
            ->  62F09288 System.IO.Ports.SerialStream
            ->  62F09310 System.Collections.Concurrent.ConcurrentQueue`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  53766868 System.Collections.Concurrent.ConcurrentQueueSegment`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  63F00020 System.Collections.Concurrent.ConcurrentQueueSegment`1+Slot[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]][]
            ->  53BF22D0 System.IO.Ports.SerialStream+SerialStreamIORequest
            ->  53BF1E8C System.Byte[]

Found 1 unique roots (run 'gcroot -all' to see all roots).

Analysis

From the data I collected using dotnet-counters and dotnet-dump, and inspecting the code for SerialStream.Unix.cs, the byte[] buffer eventually makes its way into a SerialStreamIORequest and loaded into a queue. SerialStreamIORequests should be removed from that queue when they are marked completed. It seems that either this code isn't being reached or IsCompleted is not being set when the cancellation token fires.

@dseeg dseeg added the tenet-performance Performance related issue label Jul 4, 2021
@dotnet-issue-labeler dotnet-issue-labeler bot added area-System.IO untriaged New issue has not been triaged by the area owner labels Jul 4, 2021
@ghost
Copy link

ghost commented Jul 4, 2021

Tagging subscribers to this area: @dotnet/area-system-io
See info in area-owners.md if you want to be subscribed.

Issue Details

Description

When using SerialPort.Read(byte[] buffer, int offset, int count) and a TimeoutException occures, the reference for the byte[] buffer used is not released by the underlying SerialStream used by SerialPort.

Sample repo: https://github.com/dseeg/SerialPortMemoryLeak

Application runs though 20000 iterations of trying to read from a SerialPort and timing out each time.

Configuration

  • .NET Version: .NET 5.0.301
  • OS: Raspbian 9.13 stretch
  • Architecture: ARM

Regression?

Unknown

Data

dotnet-counters

Press p to pause, r to resume, q to quit.
    Status: Running

[System.Runtime]
    % Time in GC since last GC (%)                                 0
    Allocation Rate (B / 1 sec)                               33,260
    CPU Usage (%)                                                  1
    Exception Count (Count / 1 sec)                                0
    GC Fragmentation (%)                                           7.642
    GC Heap Size (MB)                                             24
    Gen 0 GC Count (Count / 1 sec)                                 1
    Gen 0 Size (B)                                             9,884
    Gen 1 GC Count (Count / 1 sec)                                 0
    Gen 1 Size (B)                                           485,444
    Gen 2 GC Count (Count / 1 sec)                                 0
    Gen 2 Size (B)                                        25,744,976
    IL Bytes Jitted (B)                                       75,380
    LOH Size (B)                                             131,120
    Monitor Lock Contention Count (Count / 1 sec)                  0
    Number of Active Timers                                        0
    Number of Assemblies Loaded                                   19
    Number of Methods Jitted                                     735
    POH (Pinned Object Heap) Size (B)                         20,016
    ThreadPool Completed Work Item Count (Count / 1 sec)           0
    ThreadPool Queue Length                                        0
    ThreadPool Thread Count                                        0
    Working Set (MB)                                              84

dumpheap -stat

...
6604d32c       11       262276 System.Collections.Concurrent.ConcurrentQueueSegment`1+Slot[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]][]
6a2c3248    20000       560000 System.IO.Ports.SerialStream+SerialStreamIORequest
6601239c    20000       800000 System.Threading.Tasks.Task`1[[System.Int32, System.Private.CoreLib]]
66014c18    20000       880000 System.Threading.Tasks.Task+ContingentProperties
66012008    20002       880088 System.Threading.CancellationTokenSource
011b9e40    31952      2024484      Free
6a2b700c    20025     20732431 System.Byte[]
Total 135477 objects

gcroot inspection

...
53bf10f4 6a2b700c     1036
53bf157c 6a2b700c     1036
53bf1a04 6a2b700c     1036
53bf1e8c 6a2b700c     1036
53bf2314 6a2b700c     1036
53bf27a8 6a2b700c     1036
53bf2c3c 6a2b700c     1036
53bf30c4 6a2b700c     1036
53bf354c 6a2b700c     1036
53bf39f8 6a2b700c     1036
53bf3eb4 6a2b700c     1036
53bf5708 6a2b700c     1036
53bf6a70 6a2b700c     1036
53bfa4a0 6a2b700c     1036
53bfce58 6a2b700c     1036
53c01688 6a2b700c     1036
53c08bcc 6a2b700c     1036

Statistics:
      MT    Count    TotalSize Class Name
6a2b700c    20025     20732431 System.Byte[]
Total 20025 objects

> gcroot 53bfa4a0
Found 0 unique roots (run 'gcroot -all' to see all roots).
> gcroot 53bf30c4
Thread 75d4:
    7E9016F0 6A215A8C SerialPortMemoryLeak.Program.Main(System.String[]) [C:\Users\Dillon\source\repos\SerialPortMemoryLeak\SerialPortMemoryLeak\Program.cs @ 55]
        r11-44: 7e90171c
            ->  62F08D38 System.IO.Ports.SerialPort
            ->  62F09288 System.IO.Ports.SerialStream
            ->  62F09310 System.Collections.Concurrent.ConcurrentQueue`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  53766868 System.Collections.Concurrent.ConcurrentQueueSegment`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  63F00020 System.Collections.Concurrent.ConcurrentQueueSegment`1+Slot[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]][]
            ->  53BF3508 System.IO.Ports.SerialStream+SerialStreamIORequest
            ->  53BF30C4 System.Byte[]

Found 1 unique roots (run 'gcroot -all' to see all roots).
> gcroot 53bf1e8c
Thread 75d4:
    7E9016F0 6A215A8C SerialPortMemoryLeak.Program.Main(System.String[]) [C:\Users\Dillon\source\repos\SerialPortMemoryLeak\SerialPortMemoryLeak\Program.cs @ 55]
        r11-44: 7e90171c
            ->  62F08D38 System.IO.Ports.SerialPort
            ->  62F09288 System.IO.Ports.SerialStream
            ->  62F09310 System.Collections.Concurrent.ConcurrentQueue`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  53766868 System.Collections.Concurrent.ConcurrentQueueSegment`1[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]]
            ->  63F00020 System.Collections.Concurrent.ConcurrentQueueSegment`1+Slot[[System.IO.Ports.SerialStream+SerialStreamIORequest, System.IO.Ports]][]
            ->  53BF22D0 System.IO.Ports.SerialStream+SerialStreamIORequest
            ->  53BF1E8C System.Byte[]

Found 1 unique roots (run 'gcroot -all' to see all roots).

Analysis

From the data I collected using dotnet-counters and dotnet-dump, and inspecting the code for SerialStream.Unix.cs, the byte[] buffer eventually makes its way into a SerialStreamIORequest and loaded into a queue. SerialStreamIORequests should be removed from that queue when they are marked completed. It seems that either this code isn't being reached or IsCompleted is not being set when the cancellation token fires.

Author: dseeg
Assignees: -
Labels:

area-System.IO, tenet-performance, untriaged

Milestone: -

@adamsitnik adamsitnik removed the untriaged New issue has not been triaged by the area owner label Jul 5, 2021
@adamsitnik
Copy link
Member

@dseeg thank you for a very detailed bug report. Would you be interested in sending a PR with a fix?

@adamsitnik adamsitnik added this to the 7.0.0 milestone Jul 5, 2021
@dseeg
Copy link
Author

dseeg commented Jul 5, 2021

@adamsitnik Yes, I would be very interested, but fixing this will be a little bit of a learning experience for me so I'm not sure how long it will take. I've forked the repo and once its finished building (my PC is ancient by todays standards, so its taking a while) and I've had a chance to play with it, I should have a better idea.

@ghost ghost added in-pr There is an active PR which will close this issue when it is merged and removed in-pr There is an active PR which will close this issue when it is merged labels Jul 6, 2021
@freddyrios
Copy link

@adamsitnik I was also hit by a memory leak affecting all Unix that turned out to be fixed recently in .net 6: https://github.com/dotnet/runtime/pull/56866/files#diff-efd183ff76a828527dffa9f7370a0459922121146a211b15fd9a4863d4be70d5R1011-R1023

I would have commented in that PR, but it seems to be closed and the issue here is also about leak.

That unnanounced change there fixes a leak that happens due to the SerialStreamIORequest being registered to the cancellation token while also holding a reference to it. It was not a rare occurence, since it triggered by passing a cancelation token when using ReadAsync on the stream. Our dump analysis also showed plenty of SerialStreamIORequest and Task like in the current issue, except in our case it was accompanied CancellationTokenSource.CallbackNode instead of CancellationTokenSource.

@dseeg the above could explain why SerialStreamIORequest was staying around. I suggest to give it a check against the latest where that PR is in place.

SerialStreamIORequests should be removed from that queue when they are marked completed. It seems that either this code isn't being reached or IsCompleted is not being set when the cancellation token fires.

freddyrios added a commit to copenhagenatomics/CA_DataUploader that referenced this issue Sep 27, 2021
reason: dump analysis of the current memory leak points to it being in SerialPort and already fixed in dotnet 6. See dotnet/runtime#55146 (comment)
freddyrios added a commit to copenhagenatomics/CA_DataUploader that referenced this issue Sep 28, 2021
reason: dump analysis of the current memory leak pointed to it being in SerialPort and already fixed in dotnet 6. See dotnet/runtime#55146 (comment)
@dseeg
Copy link
Author

dseeg commented Oct 5, 2021

@freddyrios Just ran my sample application using 6.0.100-rc.1.21463.6 and I'm still seeing similar results as before:

...
74ab3d84    20000       560000 System.IO.Ports.SerialStream+SerialStreamIORequest
70610cdc    20002       560056 System.Threading.CancellationTokenSource
706110ac    20000       800000 System.Threading.Tasks.Task`1[[System.Int32, System.Private.CoreLib]]
70619338    20000       880000 System.Threading.Tasks.Task+ContingentProperties
0227c4e8    27220      2306468      Free
74aaec78    20011     20728083 System.Byte[]

@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Oct 10, 2021
@jeffhandley jeffhandley added the needs-further-triage Issue has been initially triaged, but needs deeper consideration or reconsideration label Oct 10, 2021
@npehrsson
Copy link

npehrsson commented Apr 11, 2022

Any progress on this issue, is there still an issue in .NET 6.0.3?
We discovered this bug as well running .NET Core 3.1, and need to know if it's solved in .NET 6 and if it is worth upgrading to solve this issue.

@danmoseley
Copy link
Member

@npehrsson I don't believe so. We would accept a PR, but otherwise it may be some time (months) before we can give it attention.

@danmoseley
Copy link
Member

If we had a fix in main, we could potentially discuss backporting to 6.0 as well depending on the risk.

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Apr 14, 2022
@jeffhandley jeffhandley removed the needs-further-triage Issue has been initially triaged, but needs deeper consideration or reconsideration label Aug 9, 2022
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Aug 10, 2022
@ghost ghost locked as resolved and limited conversation to collaborators Sep 9, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.