# Help with excessive, unpredictable GC time from string allocations
**URL:** https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334
**Category:** Performance
**Created:** [March 3, 2022, 2:36am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334 "2022-03-03T02:36:59Z")
**Posts on this page:** 13
**Page:** 1
### Author:  [@ExpandingMan](https://discourse.julialang.org/u/ExpandingMan)
#### Post date: [March 3, 2022, 2:36am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/1 "2022-03-03T02:36:59Z")
I’ve been having a hell of a time with some performance disasters when loading a large number of strings from a file.
I am hitting this in my [rewrite of a parquet reader](https://gitlab.com/ExpandingMan/Parquet2.jl) and was caught rather by surprise, because despite microbenchmarks being excellent, I eventually discovered that my actual performance on large enough files was abysmal. I am by now pretty sure that the major remaining issue is that I cannot seem to load certain types of files without hitting unpredictable and excessive GC times.
At the core of the problem (I think) is a loop in which I iterate over a view of an array from which I read strings. The strings consist of a `UInt32` giving the length of the string followed by the string itself with no padding or escape codes. You can find the loop [here](https://gitlab.com/ExpandingMan/Parquet2.jl/-/blob/a5f609cd2308cf307103abc3bfd96faa56d5574d/src/read.jl#L155-167).
I have tried multiple versions of this. First, I was writing to an array consisting entirely of `String`s so that I was creating a `String` from the views with `String(view(v, a:b))`. Obviously, this will result in allocations of the strings, though I’m not sure I understand why it seems to be leading to so much _garbage collection_ since the strings are stored in an array and not garbage collected.
Next, as an optimization, I tried an alternate version which takes place in the same loop but for which `convertvalue` is merely the identity (i.e. I write views to an array of views). I later wrap this array in a special `AbstractVector` type that simply converts the views to strings on `getindex`. Much to my surprise, the performance of this is only slightly better, and, even more surprising, does not seem to alleviate the GC issues at all. Yes, it’s possible that the GC issues are not from here, but I can’t find where else it might be from and this place is certainly a huge performance bottleneck, so it’s hard to understand how the GC can be anywhere else.
I even tried to mitigate this by doing `GC.enable(false)` only around this loop, but unsurprisingly this doesn’t help much since everything now just gets GC’d outside the loop and there are many such loops. I deem it too risky to disable GC around the loop of loops.
The thing that indicates to me that GC is such a huge problem is that `@time` consistently reports that when loading a file with several of these columns which are very large, \> 1/2 GC time.
Much to my extreme frustration, the original Parquet.jl does _not_ seem to suffer from this issue by nearly the same degree, and I have so far been unable to determine why not. They are reading the same format, and they are doing basically the same thing I am here at this point in the loop, and they do not even have a version that does this with the views.
I have quite a lot of Julia experience but this by now has me pretty stumped. This is the biggest discrepancy I’ve ever encountered between microbenchmarks of the performance critical code and my overall performance; in fact I can’t really think of another case in 6 or so years of using Julia in which my apparently optimized code runs so incredibly badly. Any help or advice would be appreciated. Thanks all!
---
### Author:  [@nilshg](https://discourse.julialang.org/u/nilshg)
#### Post date: [March 3, 2022, 6:12am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/2 "2022-03-03T06:12:18Z")
You might want to speak to @oxinabox - she explained to me long ago on Slack what was going on with Strings. As I don’t work much with Julia internals my recollection is vague, but my understanding at the time was that Strings put undue pressure on the GC because they need to be heap allocated, and every GC run has to scan all Strings to work out whether they should be collected (so this is slow even if nothing gets collected in the end).
Some packages that work around this:
- [ShortStrings](https://github.com/JuliaString/ShortStrings.jl) is what I used to use, but I think it has been superseded now
- [InlineStrings](https://github.com/JuliaStrings/InlineStrings.jl) is what CSV.jl now uses by default when reading in String data
- [WeakRefStrigns](https://github.com/JuliaData/WeakRefStrings.jl) has InlineStrings as well, plus some other types - you’d probably have to ask @quinnj to find out how this relates to just the previous package
---
### Author:  [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)
#### Post date: [March 3, 2022, 6:13am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/3 "2022-03-03T06:13:20Z")
You should also try testing this with [https://github.com/JuliaLang/julia/pull/44215](https://github.com/JuliaLang/julia/pull/44215)
---
### Author:  [@oxinabox](https://discourse.julialang.org/u/oxinabox)
#### Post date: [March 3, 2022, 12:07pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/4 "2022-03-03T12:07:41Z")
Right, yes.
When you have tens of millions of “reference” variables, basically things that use pointers under the hood, they make the “Mark” step of the mark and sweep GC slow.
Reference variables are things that are not `isbits`, so `Vector`s, `String`s, `mutable struct`s, structs/tuples with abstractly typed fields etc; Or structs with fields that are reference types (like `SubString` referencing a `String`).
Basically how a mark and sweep GC works is: when ever GC is triggered it goes through all references that exist in memory and tried to find a path from them to something that is definately in scope, if it does then it marks them and then it does a sweep step that removed everything that isn’t marked.
This is good because rather than scaling with the number of times a variable is used (which is how reference counting scales), it scaled with how many variables are declared (which is naturally less than how many times it is used as the declaration is a single use).
But it is bad that it also scales (multiplicatively) with how often a GC is triggered.
So if you have a lot of references in memory for a long time it scales badly.
To combat this Julia uses a generation GC.
Basically rather than 1 pool of reference to mark and sweep it breaks references into two Pools (you can keep exending this BTW, java has 3).
It applies a heuristic that if something has stuck around for a while (2(?) mark and sweep steps in julia’s case) it probably is going to be sticking around for a while more.
So everything starts in the Young pool, and then things that stay around for a while graduate to the Old pool.
Since most variables don’t hang around for long, one can free up a lot of memory by only marking and sweeping the young pool.
But if that doesn’t get you what you need you will need to sweep the old pool too – but this should be rare.
So what should happen is if you allocate a ton of strings say at the start of your program they quickly graduate to the Old pool and then rarely impose load on the Mark and Sweep step.
However, Julia’s generation GC doesn’t work very well (but as @Oscar_Smith linked there is a PR to hopefully fix it).
The issue #40644 shows that sometimes julia will effectively sweep both pools every time – making it functionally non-generational
>
>
> Julia has a generational mark and sweep GC.
> One of the properties of a mark and… sweep GC is that it needs to go through and mark every reference object in memory to decide if it should be swept whenever the GC runs.
> This is very expensive if you have a lot of objects in memory, and the cost is incurred even if those objects are not being freed (or even read).
> Which is where the generational aspect comes in.
> It applies a heuristic to break the objects in memory into generations.
> Things that have been referenced for a long time (in some sense) are likely to continue to be referenced, and so are moved into the older generations.
> The generational GC should mark and sweep the young generations very often, and the older generations more rarely.
> This should mean if you have some large object with lots of references that are e.g. allocated at the start of your program and kept until the end of the program, it will make the GC slow at first since it is so large and takes so long to mark, but after a little while it will move into the older generations and very rarely be marked, and so cease to have an effect on the time it takes to do normal GCs.
>
> The following examples use
> \`ZonedDateTimes\` from \`TimeZones@1.5.3\` which are for now not \`isbits\` though that is being worked on (https://github.com/JuliaTime/TimeZones.jl/issues/271).
> You can create a similar example that uses any non-\`isbits\` objects such as mutable objects, things with abstract typed fields, or things with non-isbits fields (such as \`String\` or any \`Vector\`).
> This one I had handy.
>
> You can see in this first example the generational GC working.
> At first, after the \`zdts\` are allocated there is a sharp jump in the time spent on GC, up to around 90%.
> But then after a few rounds, the \`zdts\` have moved into the older generation,
> and the time shifts spent on GC goes back down nicely to what it was at the start: around 20%
>
> \`\`\`julia
> julia\> # A function that creates a decent amount of garbage,
> little\_burn() = sum(hash, \["trashfire"^min(1000, i) for i in 1:10\_000\])
> little\_burn (generic function with 1 method)
> julia\> @time little\_burn();
> 0.091142 seconds (10.00 k allocations: 82.467 MiB, 20.53% gc time)
>
> julia\> using TimeZones
> julia\> zdts = \[now(tz"UTC") for \_ in 1:100\_000\_000\];
> julia\> for i in 1:10
> @time little\_burn()
> end
> 0.566361 seconds (10.00 k allocations: 82.467 MiB, 89.26% gc time)
> 0.620691 seconds (10.00 k allocations: 82.467 MiB, 88.32% gc time)
> 0.051410 seconds (10.00 k allocations: 82.467 MiB)
> 0.603839 seconds (10.00 k allocations: 82.467 MiB, 90.91% gc time)
> 0.060557 seconds (10.00 k allocations: 82.467 MiB, 17.61% gc time)
> 0.066966 seconds (10.00 k allocations: 82.467 MiB, 18.17% gc time)
> 0.058870 seconds (10.00 k allocations: 82.467 MiB, 19.43% gc time)
> 0.060740 seconds (10.00 k allocations: 82.467 MiB, 15.33% gc time)
> 0.064070 seconds (10.00 k allocations: 82.467 MiB, 19.75% gc time)
> 0.060747 seconds (10.00 k allocations: 82.467 MiB, 21.03% gc time)
> 0.061915 seconds (10.00 k allocations: 82.467 MiB, 18.41% gc time)
> \`\`\`
>
> However, it's very easy to run a different function that does not display the generational behavior
> \`burn()\` is identical to \`little\_burn\` but runs for 10x longer and allocates 10x as much memory.
> Like \`little\_burn\` it never actually touches the \`zdts\`.
> with \`burn\` however the GC time always stays at 60-80%.
> This is due to it triggering a full sweep of both generations of our GC.
> Thus it keeps needing to mark all of the big and complex \`zdts\` which is slow.
>
> \`\`\`julia
> julia\> # A function that creates a decent amount of garbage,
> burn() = sum(hash, \["trashfire"^min(1000, i) for i in 1:100\_000\])
> burn (generic function with 1 method)
> julia\> @time burn();
> 0.913665 seconds (100.00 k allocations: 863.183 MiB, 19.98% gc time)
>
> julia\> using TimeZones
> julia\> zdts = \[now(tz"UTC") for \_ in 1:100\_000\_000\];
> julia\> for i in 1:10
> @time burn()
> end
> 3.127583 seconds (100.00 k allocations: 863.183 MiB, 78.35% gc time)
> 2.073914 seconds (100.00 k allocations: 863.183 MiB, 64.82% gc time)
> 2.355717 seconds (100.00 k allocations: 863.183 MiB, 77.97% gc time)
> 1.842793 seconds (100.00 k allocations: 863.183 MiB, 66.04% gc time)
> 2.335667 seconds (100.00 k allocations: 863.183 MiB, 74.24% gc time)
> 1.804693 seconds (100.00 k allocations: 863.183 MiB, 66.61% gc time)
> 2.344848 seconds (100.00 k allocations: 863.183 MiB, 73.77% gc time)
> 2.396741 seconds (100.00 k allocations: 863.183 MiB, 74.44% gc time)
> 1.883768 seconds (100.00 k allocations: 863.183 MiB, 64.91% gc time)
> 2.262383 seconds (100.00 k allocations: 863.183 MiB, 77.07% gc time)
> 1.835220 seconds (100.00 k allocations: 863.183 MiB, 64.84% gc time)
> \`\`\`
>
>
> I have seen real code that takes tens of seconds to do a full mark and sweep.
> We really don't want to be running that very often. (if we are running that kind of mark and sweep too often it might even be better to OOM error)
>
>
> It seems we need to do something to the GC to have it do a full mark and sweep less often.
> This might be tweaking the heuristics.
> It might be adding another generation.
> it might be both
> [@nilshg](#):
>
> - [ShortStrings](https://github.com/JuliaString/ShortStrings.jl) is what I used to use, but I think it has been superseded now
> - [InlineStrings](https://github.com/JuliaStrings/InlineStrings.jl) is what CSV.jl now uses by default when reading in String data
> - [WeakRefStrigns](https://github.com/JuliaData/WeakRefStrings.jl) has InlineStrings as well, plus some other types - you’d probably have to ask @quinnj to find out how this relates to just the previous package
`ShortString`s basically represents a string not with a pointer to a block of memory (which would need to be tracked by the GC( but with a isbits value (like an `UInt`) that it `reinterprets` the bits out of.
`InlineString`s is `ShortString`s but implemented better, basically because @quinnj is smarter than me.
`WeakRefStrings` reexports `InlineString`s.
`WeakRefString` also however has a number of other useful string types, including the titular `WeakRefString`.
The `WeakRefString` was common in older (versions of) packages but has gone away for safer constructs, however unlike much of what replace it, it is `isbits` so didn’t incur load on the GC.
Basically, it was a `SubString` but it didn’t actually contain a julia reference to the original string, rather it contained just a raw `Ptr` to a position in the string to start reading from (+ a length).
---
### Author:  [@ExpandingMan](https://discourse.julialang.org/u/ExpandingMan)
#### Post date: [March 3, 2022, 3:04pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/5 "2022-03-03T15:04:18Z")
Thanks all for your help, especially @oxinabox for her detailed explanation!
This has been very enlightening. I thought I understood what `WeakRefStrings` was for, but now I realize I did not. In particular, despite being aware of it I did not think it was useful to me here because I thought what I was doing with the views was equivalent to using `WeakRefString`s, but now I see that this is not the case. I’m worried that it might be very tricky to use here because I have a view rather than a `Vector{UInt8}` and I’m not a priori sure whether there will be some trick involved in getting `WeakRefString`s. I’ll give it a shot and report back here.
**Edit:** In retrospect, it won’t be hard to use `WeakRefString`s here, this is guaranteed to always be either a `Vector{UInt8}` or a view of one. I’m going to make it so that there’s an option to choose one of two approaches: either allocate a new buffer containing the string data which gets copied into it via `WeakRefString`s (this is implemented by `WeakRefStrings.StringArray`) or create a special output `AbstractVector` type which contains `WeakRefString`s and exactly one reference to the original buffer, which will take up way more memory but obviate the need to allocate a whole new array.
---
### Author:  [@Benny](https://discourse.julialang.org/u/Benny)
#### Post date: [March 3, 2022, 4:33pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/6 "2022-03-03T16:33:43Z")
Let me check if I’m reading this correctly. So the marking step scales with the number of non-isbits “reference variables”, which would include both heap allocated objects and stack-allocated objects containing references, yes? What’s confusing about that to me is that I wouldn’t expect tracking 1000 arrays on the heap to be the same amount of work as 1 array on the heap and 999 views of it on the stack; once the 1st view is found, the array can just be marked.
Also, would this issue be improved at all by the recent work on escape analysis and eliding (heap) allocations?
---
### Author:  [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)
#### Post date: [March 3, 2022, 8:20pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/7 "2022-03-03T20:20:10Z")
this is half right. the part you’re missing is that what matters is the number of reference variables at the time gc is run. the advantage of putting variables on the stack is that they disappear when the function returns so GC doesn’t have to deal with the ones that have disappeared.
---
### Author:  [@stevengj](https://discourse.julialang.org/u/stevengj)
#### Post date: [March 3, 2022, 10:25pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/8 "2022-03-03T22:25:26Z")
> [@ExpandingMan](#):
>
> At the core of the problem (I think) is a loop in which I iterate over a view of an array from which I read strings.
You could use something like [StringViews.jl](https://github.com/JuliaStrings/StringViews.jl) to treat a subarray view of your array as a string. Those views are all `isbits` types that don’t require heap allocations (or copying data out of our array).
---
### Author:  [@ExpandingMan](https://discourse.julialang.org/u/ExpandingMan)
#### Post date: [March 3, 2022, 11:05pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/9 "2022-03-03T23:05:57Z")
> [@stevengj](#):
>
> You could use something like [StringViews.jl](https://github.com/JuliaStrings/StringViews.jl) to treat a subarray view of your array as a string. Those views are all `isbits` types that don’t require heap allocations (or copying data out of our array).
I don’t think this will work because the views themselves contain references and the references are causing the problem, not allocations. I already tried a vector of `UInt8` views that was wrapped in an `AbstractArray` to turn them to `String` on request but was surprised to discover this barely seemed to help (surprised because at the time I thought it must have something to do with allocations).
Anyway, I have just implemented an alternative _with copying_ using `WeakRefString`s and this has provided a _drastic_ improvement! I’m also going to implement a zero-copy alternative and I expect that will be even faster.
As a side note, in my case a small performance fix was needed for `WeakRefStrings` which I [have fixed in a PR](https://github.com/JuliaData/WeakRefStrings.jl/pull/95), so once that is merged Parquet2 strings will finally be reasonably fast.
Thanks again! (This was unbelievably frustrating before I understood what was happening, so this has been a huge relief.)
---
### Author:  [@Benny](https://discourse.julialang.org/u/Benny)
#### Post date: [March 4, 2022, 12:56am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/10 "2022-03-04T00:56:09Z")
Now I look at the code again, it clicked that the references (views) are being put in an array on the heap, so my mentioning the stack wasn’t really relevant. If the 999 views were in a vector instead of the stack, my question still stands. I’m thinking I may be imagining the GC backward? I thought the GC goes through each object on the heap, so I imagined it’d mark only 2 things: the views vector because it’s in scope, and the viewed array because it’s referenced by the vector. But if the GC scales with references, then it must be checking the reference to the views vector and its 999 views instead?
---
### Author:  [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)
#### Post date: [March 4, 2022, 1:17am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/11 "2022-03-04T01:17:02Z")
The way GC works is it goes through each object on the heap, but the way to find objects on the heap is to look at all the references from the stack to the heap.
---
### Author:  [@stevengj](https://discourse.julialang.org/u/stevengj)
#### Post date: [March 4, 2022, 2:25am UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/12 "2022-03-04T02:25:43Z")
> [@ExpandingMan](#):
>
> I don’t think this will work because the views themselves contain references and the references are causing the problem, not allocations.
You could use [UnsafeArrays.jl](https://github.com/JuliaArrays/UnsafeArrays.jl) for the array view, and then wrap a `StringView` around this. This way the views contain no references (that Julia knows about) to the heap object (only a raw pointer). (You are responsible for holding on to the original array until you are done with the unsafe views.)
This way you never have to materialize a `String` object.
---
### Author:  [@quinnj](https://discourse.julialang.org/u/quinnj)
#### Post date: [March 5, 2022, 10:49pm UTC](https://discourse.julialang.org/t/help-with-excessive-unpredictable-gc-time-from-string-allocations/77334/13 "2022-03-05T22:49:24Z")
Just a point of clarification; the InlineStrings code was moved _out_ of the WeakRefStrings.jl package into a stand-alone InlineStrings.jl package; the original InlineStrings code is still in WeakRefStrings.jl package to prevent any breakage, but is effectively “deprecated” and shouldn’t be relied upon. Only the InlineStrings.jl package has received bugfixes/improvements since the code was moved out.