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

get rid of String.intern #332

Closed
vladimirdolzhenko opened this issue Nov 13, 2016 · 38 comments
Closed

get rid of String.intern #332

vladimirdolzhenko opened this issue Nov 13, 2016 · 38 comments
Milestone

Comments

@vladimirdolzhenko
Copy link

InternCache is used in jackson for json property names only and solves the problem of extra memory footprint.
In the same time it uses String.intern - that is not an issue rather than misusage of it. The purpose of using string.intern is jvm specific: usually it maintains string literal pool (and covers internal jvm cases).

There are several known drawbacks of using intern:

  • String pool Hashtable is non-resizable table. That means: we suffer of hash code collisions when table will have items more than its size (suffer as much as many items in string.intern pool)
  • The other drawback is involve GC into that: string intern pool is subject for minor collection too. So, app suffers of using string.intern implicitly via GC phases.

There is no use cases of check the equality of strings using == and therefore no any reasons of using String.intern - the biggest profit is to have string deduplication (already achieved).

patch

===================================================================
--- src/main/java/com/fasterxml/jackson/core/util/InternCache.java  (revision 489becbfb28a41980f0d5147d6069b30fa3b5864)
+++ src/main/java/com/fasterxml/jackson/core/util/InternCache.java  (revision )
@@ -58,7 +58,7 @@
                 }
             }
         }
-        result = input.intern();
+        result = input;
         put(result, result);
         return result;
     }

Test case

The general idea behind syntenic json is used in test (a flat json structure with 10000 properties with prefix someQName) is provide lots of different property names to trigger usage of string.intern within InternCache - that is close to real apps use cases where amount of unique property names is on a scale from hundreds to thousands.

{
    "someQName0": 0,
    "someQName1": 1,
    ....
    "someQName9999": 9999
}

JMH test

Let's measure performance of a single json parse with interting and w/o it: PerfInternCache.java

Benchmark                   Mode  Cnt     Score     Error  Units
-PerfInternCache.intern      avgt    5  4098.696 ± 164.484  us/op
+PerfInternCache.noIntern    avgt    5  2320.159 ± 204.301  us/op

GC

Another test is to measure how intern is affecting implicitly via GC: handle 10k the same jsons as we use in previous test (the use case is very very close to real one in real apps like web service / microsevices):
InternCache GC timings java test

Run it with -verbose:gc -XX:+PrintGCDetails -Xloggc:gc.log

and after that get the total GC pause time
$ grep "GC" gc.log | grep "Times: " | awk '{S+=$8}END{print S}'

-intern      0.1907254 +- 0.00469 sec
+w/o intern  0.07665   +- 0.00498 sec

Conclusion

Using intern harms application performance as explicitly via more expencive InternCache.intern and implicitly via GC. In the same time we keep memory footprint on the same low possible level.

vladimirdolzhenko added a commit to vladimirdolzhenko/jackson-core that referenced this issue Nov 13, 2016
get rid of String.intern
@IRus
Copy link

IRus commented Nov 13, 2016

@vladimirdolzhenko what about other property sizes? Like 10, 100, 1000, 100_000?

vladimirdolzhenko added a commit to vladimirdolzhenko/jackson-core that referenced this issue Nov 13, 2016
get rid of String.intern
@vladimirdolzhenko
Copy link
Author

vladimirdolzhenko commented Nov 13, 2016

@IRus

GC pauses in ms

name/size 100 1000 10k 100k
intern 2.249 ± 0.229 14.288 ± 0.554 192.375 ± 5.801 1395.513 ± 33.007
w/o intern 1.987 ± 0.130 11.974 ± 0.279 75.822 ± 6.693 828.542 ± 74.948

@IRus
Copy link

IRus commented Nov 13, 2016

What about PerfInternCache?

@vladimirdolzhenko
Copy link
Author

@IRus

PerfInternCache in us/op:

name 100 1000 10k 100k
intern 13.879 ± 0.523 377.937 ± 27.612 4098.696 ± 164.484 31396.578 ± 2325.685
w/o intern 13.472 ± 0.438 205.322 ± 9.720 2320.159 ± 204.301 17292.832 ± 1290.865

@cowtowncoder
Copy link
Member

There is JsonFactory.Feature.INTERN_FIELD_NAMES to use if you prefer no intern()ing.]

@vladimirdolzhenko
Copy link
Author

@cowtowncoder I know about that flag - the problem that it is enabled by default and that kind of optimisation harms app more neither having it switched off.

What's the point to have such kind of degradation flag rather to fix it and make apps (bearing in mind the spread around of json) using jackon feel a bit better ?

@vladimirdolzhenko
Copy link
Author

vladimirdolzhenko commented Nov 14, 2016

@cowtowncoder

disabled flag INTERN_FIELD_NAMES PerfInternCache2.java (the numbers from another box - no any reasons to compare absolute values with prev one)

Benchmark                  (intern)  (size)  Mode  Cnt      Score      Error  Units
PerfInternCache.parseJson      true     100  avgt    5      5.968 ±    0.066  us/op
PerfInternCache.parseJson      true    1000  avgt    5     74.035 ±   10.903  us/op
PerfInternCache.parseJson      true   10000  avgt    5    878.049 ±   13.579  us/op
PerfInternCache.parseJson      true  100000  avgt    5  26794.594 ± 8337.486  us/op
PerfInternCache.parseJson     false     100  avgt    5      5.814 ±    0.635  us/op
PerfInternCache.parseJson     false    1000  avgt    5     72.724 ±    1.257  us/op
PerfInternCache.parseJson     false   10000  avgt    5    937.059 ±  297.084  us/op
PerfInternCache.parseJson     false  100000  avgt    5  10000.686 ±  333.828  us/op

I would really consider to disable that flag by default.

@vlsi
Copy link

vlsi commented Nov 14, 2016

@vladimirdolzhenko , would you please add -prof gc (aka .addProfiler(GCProfiler.class)) outputs? (I mainly mean gc.alloc.rate.norm)

@vladimirdolzhenko
Copy link
Author

vladimirdolzhenko commented Nov 14, 2016

@vlsi that's all for Enabled/Disable flag only

Benchmark                                                   (intern)  (size)  Mode  Cnt         Score          Error   Units
PerfInternCache.parseJson                                       true     100  avgt    5         5.817 ±        0.084   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true     100  avgt    5        70.810 ±        1.022  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true     100  avgt    5       432.005 ±        0.001    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space               true     100  avgt    5        71.433 ±      106.854  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm          true     100  avgt    5       436.155 ±      658.138    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space           true     100  avgt    5         0.436 ±        3.689  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm      true     100  avgt    5         2.672 ±       22.601    B/op
PerfInternCache.parseJson:·gc.count                             true     100  avgt    5         6.000                 counts
PerfInternCache.parseJson:·gc.time                              true     100  avgt    5         5.000                     ms
PerfInternCache.parseJson                                       true    1000  avgt    5        74.988 ±        1.181   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true    1000  avgt    5         5.494 ±        0.087  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true    1000  avgt    5       432.070 ±        0.021    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space               true    1000  avgt    5        12.783 ±      110.068  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm          true    1000  avgt    5      1006.205 ±     8663.731    B/op
PerfInternCache.parseJson:·gc.count                             true    1000  avgt    5         1.000                 counts
PerfInternCache.parseJson:·gc.time                              true    1000  avgt    5         2.000                     ms
PerfInternCache.parseJson                                       true   10000  avgt    5       909.903 ±        9.144   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true   10000  avgt    5         0.495 ±        0.005  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true   10000  avgt    5       472.822 ±        0.008    B/op
PerfInternCache.parseJson:·gc.count                             true   10000  avgt    5           ≈ 0                 counts
PerfInternCache.parseJson                                       true  100000  avgt    5     25160.112 ±     2143.684   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true  100000  avgt    5       388.930 ±       33.593  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true  100000  avgt    5  10258886.390 ±        2.419    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space               true  100000  avgt    5       361.152 ±      781.211  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm          true  100000  avgt    5   9605141.415 ± 20734528.664    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space           true  100000  avgt    5         0.555 ±        2.995  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm      true  100000  avgt    5     14668.970 ±    78754.601    B/op
PerfInternCache.parseJson:·gc.count                             true  100000  avgt    5         4.000                 counts
PerfInternCache.parseJson:·gc.time                              true  100000  avgt    5         9.000                     ms
PerfInternCache.parseJson                                      false     100  avgt    5         6.237 ±        0.249   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false     100  avgt    5        66.044 ±        2.671  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false     100  avgt    5       432.006 ±        0.001    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space              false     100  avgt    5        71.421 ±       98.050  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm         false     100  avgt    5       468.240 ±      662.365    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space          false     100  avgt    5         0.439 ±        3.517  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm     false     100  avgt    5         2.844 ±       22.728    B/op
PerfInternCache.parseJson:·gc.count                            false     100  avgt    5         6.000                 counts
PerfInternCache.parseJson:·gc.time                             false     100  avgt    5        13.000                     ms
PerfInternCache.parseJson                                      false    1000  avgt    5        81.275 ±       27.249   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false    1000  avgt    5         5.099 ±        1.653  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false    1000  avgt    5       432.076 ±        0.040    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space              false    1000  avgt    5        12.792 ±      110.141  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm         false    1000  avgt    5      1221.939 ±    10521.259    B/op
PerfInternCache.parseJson:·gc.count                            false    1000  avgt    5         1.000                 counts
PerfInternCache.parseJson:·gc.time                             false    1000  avgt    5         3.000                     ms
PerfInternCache.parseJson                                      false   10000  avgt    5       782.931 ±       23.195   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false   10000  avgt    5         0.576 ±        0.017  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false   10000  avgt    5       472.707 ±        0.020    B/op
PerfInternCache.parseJson:·gc.count                            false   10000  avgt    5           ≈ 0                 counts
PerfInternCache.parseJson                                      false  100000  avgt    5     10713.712 ±      554.663   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false  100000  avgt    5       774.272 ±       39.791  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false  100000  avgt    5   8698649.639 ±        0.518    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space              false  100000  avgt    5       815.419 ±      569.952  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm         false  100000  avgt    5   9175274.322 ±  6805920.526    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space          false  100000  avgt    5         2.493 ±        3.869  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm     false  100000  avgt    5     27976.282 ±    43304.868    B/op
PerfInternCache.parseJson:·gc.count                            false  100000  avgt    5        12.000                 counts
PerfInternCache.parseJson:·gc.time                             false  100000  avgt    5        38.000                     ms

@vlsi
Copy link

vlsi commented Nov 14, 2016

That does look strange.
intern=true => allocates 10258886 bytes/iteration ~ 9.8 MiB/iteration
intern=false => allocates 8698649/iteration ~ 8.3 MiB/iteration

It sounds like "string intern makes memory allocation higher", that is counter-intuitive, at least at the first sight

@IRus
Copy link

IRus commented Nov 14, 2016

This benchmark was very short in terms of time, there are results by @isopov:

https://gist.github.com/isopov/b215f473deb4ef40118c00f054dc204c

Benchmark                                                   (intern)  (size)  Mode  Cnt         Score        Error   Units
PerfInternCache.parseJson                                       true     100  avgt   25         5.582 ±      0.092   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true     100  avgt   25        76.578 ±      1.262  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true     100  avgt   25       448.001 ±      0.001    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space               true     100  avgt   25        76.267 ±      4.881  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm          true     100  avgt   25       446.030 ±     26.011    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space           true     100  avgt   25         0.030 ±      0.007  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm      true     100  avgt   25         0.178 ±      0.041    B/op
PerfInternCache.parseJson:·gc.count                             true     100  avgt   25       156.000               counts
PerfInternCache.parseJson:·gc.time                              true     100  avgt   25       163.000                   ms
PerfInternCache.parseJson                                       true    1000  avgt   25        64.844 ±      3.353   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true    1000  avgt   25         6.616 ±      0.306  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true    1000  avgt   25       448.012 ±      0.001    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space               true    1000  avgt   25         6.695 ±      6.825  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm          true    1000  avgt   25       456.683 ±    468.284    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space           true    1000  avgt   25         0.040 ±      0.060  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm      true    1000  avgt   25         2.808 ±      4.220    B/op
PerfInternCache.parseJson:·gc.count                             true    1000  avgt   25         9.000               counts
PerfInternCache.parseJson:·gc.time                              true    1000  avgt   25        25.000                   ms
PerfInternCache.parseJson                                       true   10000  avgt   25       727.737 ±     24.616   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true   10000  avgt   25         0.641 ±      0.020  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true   10000  avgt   25       488.132 ±      0.004    B/op
PerfInternCache.parseJson:·gc.count                             true   10000  avgt   25           ≈ 0               counts
PerfInternCache.parseJson                                       true  100000  avgt   25     23717.280 ±   1526.254   us/op
PerfInternCache.parseJson:·gc.alloc.rate                        true  100000  avgt   25       416.108 ±     24.800  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                   true  100000  avgt   25  10281132.282 ±   9036.086    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space               true  100000  avgt   25       428.100 ±     37.795  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm          true  100000  avgt   25  10577485.930 ± 661648.403    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space           true  100000  avgt   25         0.254 ±      0.160  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm      true  100000  avgt   25      6442.022 ±   4240.444    B/op
PerfInternCache.parseJson:·gc.count                             true  100000  avgt   25       148.000               counts
PerfInternCache.parseJson:·gc.time                              true  100000  avgt   25       390.000                   ms
PerfInternCache.parseJson                                      false     100  avgt   25         5.721 ±      0.277   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false     100  avgt   25        74.963 ±      3.536  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false     100  avgt   25       448.001 ±      0.001    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space              false     100  avgt   25        75.394 ±      5.015  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm         false     100  avgt   25       450.417 ±     19.277    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space          false     100  avgt   25         0.029 ±      0.009  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm     false     100  avgt   25         0.173 ±      0.054    B/op
PerfInternCache.parseJson:·gc.count                            false     100  avgt   25       155.000               counts
PerfInternCache.parseJson:·gc.time                             false     100  avgt   25       124.000                   ms
PerfInternCache.parseJson                                      false    1000  avgt   25        64.212 ±      1.366   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false    1000  avgt   25         6.659 ±      0.139  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false    1000  avgt   25       448.012 ±      0.001    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space              false    1000  avgt   25         7.439 ±      6.966  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm         false    1000  avgt   25       497.387 ±    465.968    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space          false    1000  avgt   25         0.039 ±      0.055  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm     false    1000  avgt   25         2.611 ±      3.689    B/op
PerfInternCache.parseJson:·gc.count                            false    1000  avgt   25        10.000               counts
PerfInternCache.parseJson:·gc.time                             false    1000  avgt   25        23.000                   ms
PerfInternCache.parseJson                                      false   10000  avgt   25       736.818 ±     21.847   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false   10000  avgt   25         0.633 ±      0.019  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false   10000  avgt   25       488.133 ±      0.004    B/op
PerfInternCache.parseJson:·gc.count                            false   10000  avgt   25           ≈ 0               counts
PerfInternCache.parseJson                                      false  100000  avgt   25      9299.408 ±    362.041   us/op
PerfInternCache.parseJson:·gc.alloc.rate                       false  100000  avgt   25       894.241 ±     34.802  MB/sec
PerfInternCache.parseJson:·gc.alloc.rate.norm                  false  100000  avgt   25   8697698.945 ±   7290.094    B/op
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space              false  100000  avgt   25       913.435 ±     50.882  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Eden_Space.norm         false  100000  avgt   25   8890667.834 ± 449734.489    B/op
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space          false  100000  avgt   25         1.296 ±      0.654  MB/sec
PerfInternCache.parseJson:·gc.churn.PS_Survivor_Space.norm     false  100000  avgt   25     12487.399 ±   6192.507    B/op
PerfInternCache.parseJson:·gc.count                            false  100000  avgt   25       227.000               counts
PerfInternCache.parseJson:·gc.time                             false  100000  avgt   25       422.000                   ms

@cowtowncoder
Copy link
Member

cowtowncoder commented Nov 14, 2016

@vladimirdolzhenko I don't agree with our assessment of its harmfulness, based on invalid (as general statement) assumptions on usage. Performance to test is for databinding; and databind does in fact benefit from equality checks. You would have known this if you had asked; or perhaps dug around.
As to what is typical number of unique names, I don't know; but nor is there anything to suggest specific number.

I think it is very arrogant of you to make a demand of removing a feature that has served users well for, what, 7 years now. If you do not want the feature, turn it off. I keep mine on.

@vladimirdolzhenko
Copy link
Author

@cowtowncoder my test case is based a typical pattern of json we use over several teams. As well I pretty sure that lots of stuff have been changed over past 7 years, json patterns and its use-cases - and it is worth to review it again.

If you pay attention a bit more - my original point is to stop using String.intern - in the same time idea of InternCache to have string deduplication is good.

@vladimirdolzhenko
Copy link
Author

@cowtowncoder

Performance to test is for databinding.

maybe in that case turn it on for databinding while keep off for other use-cases ?

@IRus
Copy link

IRus commented Nov 14, 2016

@cowtowncoder so we need test for object mapper read/write use cases?

@cowtowncoder
Copy link
Member

@IRus At this point you should be disabling this for your use case if that makes most sense for you, based on tests.

@vladimirdolzhenko if you want to discuss this further, issue tracker is not the best way: jackson-dev list would be better. I am not completely against changing of defaults, but this can not be made solely based on feedback from one user or group of users. I suspect that choice really does not have huge impact, overall, for most users.

As to defaulting for some use cases, that could be one option if consensus opinion is that interning in addition to canonicalization (handled by symbol table, not InternCache, which also reduces likelihood of unintentional retention).
If change was to be made, that would be for Jackson 3.x, development of which will probably start early 2017. It will update baseline requirement to Java 8, and may contain bigger changes to defaults than minor patches.

@cowtowncoder cowtowncoder reopened this Nov 20, 2016
@cowtowncoder
Copy link
Member

cowtowncoder commented Nov 20, 2016

Thank you for raising this on mailing list. I'll add comments there soon too, but I thought I'll add one more data point.
@IRus one way to test effect on databind is via:

https://github.com/FasterXML/jackson-benchmarks

and I added a no-interning variant. With my quick test there, disabling interning for test case (which is original from jvm-serializers) reduces throughput by about 10%, from about 360,000/second to about ~330,000/second (i may run longer test later on to double-check).
This is not earth-shattering, but significant. Amount of symbols in test case is rather small (about 20 or so I think), but for throughput that shouldn't matter that much. So this would be compared to other effects when considering usefulness.

@vladimirdolzhenko
Copy link
Author

vladimirdolzhenko commented Nov 20, 2016

ok, let me have a look into that

@vladimirdolzhenko
Copy link
Author

vladimirdolzhenko commented Nov 27, 2016

as JsonFactory uses
protected final transient ByteQuadsCanonicalizer _byteSymbolCanonicalizer = ByteQuadsCanonicalizer.createRoot();

that has hard-coded enabled intern = true (see createRoot(int seed)) - therefore it does not matter for test - INTERN_FIELD_NAMES is enabled or not

I added to InternCache

private static final boolean INTERN = Boolean.getBoolean("internCache");

////
        result = INTERN ? input.intern() : input;
        put(result, result);
        return result;
    }
////

modified JsonInternReadVanilla
java -DinternCache=true -jar target/microbenchmarks.jar "com.fasterxml.jackson.perf.json.JsonInternReadVanilla.readNodeCitmCatalog" -wi 7 -i 7 -f 3 -t 2

as that benchmark uses json/citm_catalog_ws.json with lots of different properties

InternCache:off
Benchmark                                   Mode  Cnt    Score   Error  Units
JsonInternReadVanilla.readNodeCitmCatalog  thrpt   21  646.612 ± 7.731  ops/s

InternCache:on
Benchmark                                   Mode  Cnt    Score    Error  Units
JsonInternReadVanilla.readNodeCitmCatalog  thrpt   21  656.728 ± 11.987  ops/s

@cowtowncoder
Copy link
Member

@vladimirdolzhenko that true only matters for root instance which is a blueprint, instance only used for sharing underlying symbol tables: it is never directly used for operation. Child instances must be (and are) created via makeChild: this is necessary to avoid concurrent modifications. So I don't think additional work-arounds are needed.

@vladimirdolzhenko
Copy link
Author

@cowtowncoder
JsonNoInternReadVanillaTestCase.java is just extracted unit test - the same as used in benchmark JsonNoInternReadVanilla.java

As for me - test reaches InternCache.intern for all values - and that means that test and benchmark are not correct - because they uses intern = true despite of disabling it through factory feature.

Appreciate if you have a look into that as well.

@cowtowncoder
Copy link
Member

Ok, that is peculiar. Tests look legit to me. And I assume this is with 2.8(.5) (or master)

@cowtowncoder
Copy link
Member

Actually I think there are calls to InternCache by databind, for intern()ing POJO property names; this is necessary for identity comparison to have any effect at data binding level (if only one is intern()ed there's no real benefit).

Calls are via PropertyName, and do not check for the core package feature: currently this code path has no access to configuration. Ideally it'd be possible to disable this, but that would require refactoring, and set of property names as specified by POJOs is more tightly bounded than property name domain for streaming parser.

@vladimirdolzhenko
Copy link
Author

@cowtowncoder sorry I don't get the point is necessary for identity comparison - there are no places where == is used (and it is ideologically wrong)

Do you consider benchmark results ?

@cowtowncoder
Copy link
Member

@vladimirdolzhenko jackson-core does not use identity comparisons, but jackson-databind does. If nothing else, it'd be taken into account by String.equals() where identity is the first thing checked. I think there are couple of lookup tables where this is written out as well.

Results I have gotten on my tests are sufficient for me to consider benefits of intern()ing as an option.
Other results for different case can be helpful, but I don't consider them more representative.
If I find time to at some point I will have a look at alternative tests: but there are many other issues to work on so this may take a while. I appreciate your work on providing these results.

At this point I see no compelling reason for removing support for intern()ing; I am open to possibility of changing defaults for 3.0.

@amanhigh
Copy link

We are also facing issue in our Production Application. this issue gets aggravated as we reach more CPU Usage.

Stack Trace Count Duration
com.fasterxml.jackson.core.util.InternCache.intern(String) 50,075 1h 21 min
com.fasterxml.jackson.core.sym.ByteQuadsCanonicalizer.addName(String, int[], int) 50,075 1h 21 min
com.fasterxml.jackson.core.sym.ByteQuadsCanonicalizer.rehash() 43,947 1h 4m
com.fasterxml.jackson.core.json.UTF8StreamJsonParser.addName(int[], int, int) 6,128 17m 13s

@cowtowncoder
Copy link
Member

@amanhigh This is very likely due to sub-optimal usage of ObjectMapper, and not due to interning. This method should not become hot spot unless domain of property names is unbounded.
So while you can disable interning (and even canonicalization), this has so far always been due to either not reusing ObjectMapper, or, in some cases, not closing JsonParser instances (not reading until end-of-input OR closing).

But if you have synthetic names, on the other hand, you do want to disable both (disabling canonicalization is actually sufficient).

@amanhigh
Copy link

amanhigh commented Jan 6, 2017

@cowtowncoder We used single instance of Object Mapper with readValue operating on byte stream. We did get a significant improment in 99th Percentile after disabling intern caching.

We haved Java Models for all classes and don't deserialize as map hence property names are bounded. I am not sure if same applies to Keys of hashMap as well as some properties are HashMaps with varying keys.

@cowtowncoder
Copy link
Member

@amanhigh I do not doubt that you saw a significant improvement, but everything I know about interning and canonicalization suggests that the problem is because Symbol table is not being reused.
If it was, interning would only ever occur once per unique String, and this really should not cause performance problems after steady state.

Now... there are a few reasons why underlying, per-JsonFactory symbol table might not be reused.
Not using same ObjectMapper (or, if low-level operation, JsonFactory) is a common cause but not the only one. Another common cause is that JsonParser instance is not closed, either implicitly (by reading all content and encountering end-of-input) or explicitly (via close()).

But there is another possibility: if number of distinct symbols (property names) is really large (in order of tens of thousands), there is size limit (something like 40,000 or so), symbol table is not reused.
This is a protective measure to prevent OOME and certain types of DoS attacks.

I suppose that in latter case you could get into trouble because intern() calls would effectively not be cached. If this is the case, I would be interested in figuring out better ways to handle it.

My main concern here is still the fact that I believe there are many use cases where intern()ing is beneficial, and that change to better support other use cases would have detrimental effect on these.

I am also open to being proven wrong on benefits: for example, it is possible that newest JVMs may have different kinds of trade-offs. I hope to find a way to validate my knowledge here.
The reason I may seem slow is simply that there are many important things to work on -- I think this is one too -- but juggling through many things makes it harder for me to get deep understanding.
So even if it may not seem like it, I really appreciate your help @amanhigh (and everyone else too).

@cowtowncoder
Copy link
Member

@amanhigh One more thing I just realized: your mention of Maps. This might be the problem wrt unbounded nature -- what matters at low level really is JSON keys.

Would there be a way for you to locally modify jackson-core jar, adding minor diagnostics in ByteQuadsCanonicalizer? I know that's a lot to ask and wish there were hooks in place but those do not exist at this moment. But what would be interesting would be to know if table is flushed, and/or what happens when table is being closed.
I suspect that you could well be hitting maximum size -- if so, symptoms would make sense.
And this could guide efforts appropriately, addressing specific usage. And maybe make it easier to repro the issue with synthetic data?

@vladimirdolzhenko
Copy link
Author

@cowtowncoder I tried to persuade you that you don't understand String.intern properly and misuse it - with examples, benchmarks and so on - and I see that you would not take any of them into account

@relgames
Copy link

My main concern here is still the fact that I believe there are many use cases where intern()ing is beneficial, and that change to better support other use cases would have detrimental effect on these.

Could you tell those use cases please? Maybe publish your benchmarks as well if you get some time.

@cowtowncoder
Copy link
Member

@relgames testing I did was by modifying existing tests like:

https://github.com/FasterXML/jackson-benchmarks
https://github.com/cowtowncoder/java-json-performance-benchmarks

by forcible disabling interning and comparing results to ones I get when interning is enabled.
Similarly I have earlier tested jvm-serializers usage. All of these have relatively small vocabulary.

While I would not mind sharing results (or someone else running those), I do not see enough value for me to spend more time on general question; and specifically not in being convinced to remove ability to intern() keys. Users are free to change the setting as they see fit; same goes for frameworks using Jackson.

@IRus
Copy link

IRus commented May 17, 2017

@relgames
Copy link

"In almost every project we were taking care of, removing String.intern() from the hotpaths, or optionally replacing it with a handrolled deduplicator, was the very profitable performance optimization. Do not use String.intern() without thinking very hard about it, okay?"

Summary from JDK developer.

@cowtowncoder
Copy link
Member

cowtowncoder commented May 20, 2017

@relgames Yes? I have thought about it more than people commenting here. Article itself is fine and properly discusses challenges. It may indeed be the case that for some usage turning off intern()ing makes sense -- if you end up having hundreds of thousands of symbols. I do not think this applies to majority of JSON usage.

Given that interning can easily be turned off by those who want to do that:

factory.disable(JsonFactory.Feature.INTERN_FIELD_NAMES);

and since there is clear performance improvement by test I have (jackson-benchmarks), there's little to discuss here. I do not see any point in removing the feature.
At most it might make sense to figure if default settings should differ between usage via databinding (where intern()ing can help), or by direct setup as streaming parser (at which level there is likely no benefit) for Jackson 3.x. I will create a new issue for such discussion.

@FasterXML FasterXML locked and limited conversation to collaborators May 20, 2017
@cowtowncoder
Copy link
Member

For what it's worth, there's follow up issue: #378 -- and I have some good news to share there.

@cowtowncoder cowtowncoder added this to the 3.0.0 milestone Aug 29, 2018
@cowtowncoder
Copy link
Member

And for TL;DNR observers, Jackson 3.0 DOES NOT use String.intern() by default,
and the implementation is such that it typically performs at same level with or without intern()ing, including usage through databinding.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants