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

Concurrency-related deserialization issue when G1GC is enabled #274

Open
perlun opened this issue Feb 4, 2019 · 7 comments
Open

Concurrency-related deserialization issue when G1GC is enabled #274

perlun opened this issue Feb 4, 2019 · 7 comments

Comments

@perlun
Copy link

perlun commented Feb 4, 2019

Hi,

I've spent a lot of time debugging this issue lately, which started out as random SIGSEGVs on some of our customer servers. Here are the full details, quoting from the README.md in the repro repository.

Please let me know if you have any suggestions or need more info, I'll happily help with the debugging of this.


fst-concurrency-issue

Demonstrates a problem in the fst library.

Details & background

#235 describes an issue related to how the FSTConfiguration class in fst is not thread safe.

#270 describes another issue with a user experiencing SIGSEGV errors in the Java process.

We were seeing the latter in our application while put under load, which led us to start investigating this further. Here are the results of this investigation. This repository illustrates how to reproduce our current bug, which is only displayed when using one of the following:

  • Java 11 (without changing GC settings; uses G1GC by default)
  • Java 8, with G1GC enabled: -XX:+UseG1GC

This repro project does not cause the JVM to crash, but we feel confident enough anyway that our crashes have the same root cause as these (managed) exceptions. When excluding FST from our application, using another serialization library, our SIGSEGV errors go away completely.

How to run

$ ./gradlew test (or load the project in IntelliJ IDEA/some other Java IDE, and use its test runner).

When run multiple times, the problem is exhibited. From my experience, when running it 10 times it will fail about 3-4 times with fst 2.57.

(If running on the command line, the exceptions will be logged to an HTML file; normally, build/reports/tests/test/index.html - its location will be printed by Gradle. Full exception details are not printed to stdout.)

I also made it easy to test this with older versions of fst - see build.gradle for more details. From what I can tell, the bug seems to be present on all 2.xx versions of fst.

Disabling parallelization

I experimented with setting NUMBER_OF_THREADS to 1, i.e. minimize parallelism, since we were thinking that the root cause here might not be strictly concurrency-related but rather triggered by unexpected GC behavior (= fst semantics only working reliably with ParallelGC, the default GC in Java 8).

Interestingly enough, I could not reproduce the errors this way, which leads to the conclusion that the error is likely to be a concurrency bug after all.

Example exceptions

Provided for convenience only; these were the exceptions I noted when running the tests now about 10-15 times.

java.io.IOException: Failed to read the next byte

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.io.IOException: Failed to read the next byte
	at FSTSerializationTest.tryAndReProduceBug(FSTSerializationTest.java:68)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:108)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:661)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:869)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1193)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:126)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
	at org.testng.TestRunner.privateRun(TestRunner.java:744)
	at org.testng.TestRunner.run(TestRunner.java:602)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:380)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:375)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:340)
	at org.testng.SuiteRunner.run(SuiteRunner.java:289)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1301)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1226)
	at org.testng.TestNG.runSuites(TestNG.java:1144)
	at org.testng.TestNG.run(TestNG.java:1115)
	at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.runTests(TestNGTestClassProcessor.java:139)
	at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.stop(TestNGTestClassProcessor.java:89)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.stop(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:131)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:155)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:137)
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.io.IOException: Failed to read the next byte
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
	at FSTSerializationTest.tryAndReProduceBug(FSTSerializationTest.java:64)
	... 50 more
Caused by: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.io.IOException: Failed to read the next byte
	at FSTSerializationTest.lambda$tryAndReProduceBug$0(FSTSerializationTest.java:55)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	... 1 more
Caused by: java.io.IOException: java.io.IOException: java.io.IOException: Failed to read the next byte
	at FSTSerializationTest.readObject(FSTSerializationTest.java:78)
	at FSTSerializationTest.lambda$tryAndReProduceBug$0(FSTSerializationTest.java:51)
	... 5 more
Caused by: java.io.IOException: java.io.IOException: Failed to read the next byte
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:247)
	at FSTSerializationTest.readObject(FSTSerializationTest.java:75)
	... 6 more
Caused by: java.io.IOException: Failed to read the next byte
	at org.nustaq.serialization.coders.FSTStreamDecoder.readFByte(FSTStreamDecoder.java:294)
	at org.nustaq.serialization.coders.FSTStreamDecoder.readObjectHeaderTag(FSTStreamDecoder.java:98)
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:344)
	at org.nustaq.serialization.FSTObjectInput.readObjectFields(FSTObjectInput.java:713)
	at org.nustaq.serialization.FSTObjectInput.instantiateAndReadNoSer(FSTObjectInput.java:566)
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:374)
	at org.nustaq.serialization.FSTObjectInput.readObjectInternal(FSTObjectInput.java:331)
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:311)
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:245)
	... 7 more

java.lang.NullPointerException at FSTObjectInput.java:357

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.lang.NullPointerException
	at FSTSerializationTest.tryAndReProduceBug(FSTSerializationTest.java:68)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:108)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:661)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:869)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1193)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:126)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
	at org.testng.TestRunner.privateRun(TestRunner.java:744)
	at org.testng.TestRunner.run(TestRunner.java:602)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:380)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:375)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:340)
	at org.testng.SuiteRunner.run(SuiteRunner.java:289)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1301)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1226)
	at org.testng.TestNG.runSuites(TestNG.java:1144)
	at org.testng.TestNG.run(TestNG.java:1115)
	at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.runTests(TestNGTestClassProcessor.java:139)
	at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.stop(TestNGTestClassProcessor.java:89)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.stop(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:131)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:155)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:137)
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.lang.NullPointerException
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
	at FSTSerializationTest.tryAndReProduceBug(FSTSerializationTest.java:64)
	... 50 more
Caused by: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.lang.NullPointerException
	at FSTSerializationTest.lambda$tryAndReProduceBug$0(FSTSerializationTest.java:55)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	... 1 more
Caused by: java.io.IOException: java.io.IOException: java.lang.NullPointerException
	at FSTSerializationTest.readObject(FSTSerializationTest.java:78)
	at FSTSerializationTest.lambda$tryAndReProduceBug$0(FSTSerializationTest.java:51)
	... 5 more
Caused by: java.io.IOException: java.lang.NullPointerException
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:247)
	at FSTSerializationTest.readObject(FSTSerializationTest.java:75)
	... 6 more
Caused by: java.lang.NullPointerException
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:357)
	at org.nustaq.serialization.FSTObjectInput.readObjectFields(FSTObjectInput.java:713)
	at org.nustaq.serialization.FSTObjectInput.readObjectCompatibleRecursive(FSTObjectInput.java:635)
	at org.nustaq.serialization.FSTObjectInput.readObjectCompatible(FSTObjectInput.java:574)
	at org.nustaq.serialization.FSTObjectInput.instantiateAndReadNoSer(FSTObjectInput.java:559)
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:374)
	at org.nustaq.serialization.FSTObjectInput.readObjectFields(FSTObjectInput.java:713)
	at org.nustaq.serialization.FSTObjectInput.instantiateAndReadNoSer(FSTObjectInput.java:566)
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:374)
	at org.nustaq.serialization.FSTObjectInput.readObjectInternal(FSTObjectInput.java:331)
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:311)
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:245)
	... 7 more

java.lang.RuntimeException: unknown object tag -19

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.lang.RuntimeException: unknown object tag -19
	at FSTSerializationTest.tryAndReProduceBug(FSTSerializationTest.java:68)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:108)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:661)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:869)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1193)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:126)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
	at org.testng.TestRunner.privateRun(TestRunner.java:744)
	at org.testng.TestRunner.run(TestRunner.java:602)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:380)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:375)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:340)
	at org.testng.SuiteRunner.run(SuiteRunner.java:289)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1301)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1226)
	at org.testng.TestNG.runSuites(TestNG.java:1144)
	at org.testng.TestNG.run(TestNG.java:1115)
	at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.runTests(TestNGTestClassProcessor.java:139)
	at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.stop(TestNGTestClassProcessor.java:89)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.stop(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:131)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:155)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:137)
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.lang.RuntimeException: unknown object tag -19
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
	at FSTSerializationTest.tryAndReProduceBug(FSTSerializationTest.java:64)
	... 50 more
Caused by: java.lang.RuntimeException: java.io.IOException: java.io.IOException: java.lang.RuntimeException: unknown object tag -19
	at FSTSerializationTest.lambda$tryAndReProduceBug$0(FSTSerializationTest.java:55)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	... 1 more
Caused by: java.io.IOException: java.io.IOException: java.lang.RuntimeException: unknown object tag -19
	at FSTSerializationTest.readObject(FSTSerializationTest.java:78)
	at FSTSerializationTest.lambda$tryAndReProduceBug$0(FSTSerializationTest.java:51)
	... 5 more
Caused by: java.io.IOException: java.lang.RuntimeException: unknown object tag -19
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:247)
	at FSTSerializationTest.readObject(FSTSerializationTest.java:75)
	... 6 more
Caused by: java.lang.RuntimeException: unknown object tag -19
	at org.nustaq.serialization.FSTObjectInput.instantiateSpecialTag(FSTObjectInput.java:434)
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:364)
	at org.nustaq.serialization.FSTObjectInput.readObjectFields(FSTObjectInput.java:713)
	at org.nustaq.serialization.FSTObjectInput.instantiateAndReadNoSer(FSTObjectInput.java:566)
	at org.nustaq.serialization.FSTObjectInput.readObjectWithHeader(FSTObjectInput.java:374)
	at org.nustaq.serialization.FSTObjectInput.readObjectInternal(FSTObjectInput.java:331)
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:311)
	at org.nustaq.serialization.FSTObjectInput.readObject(FSTObjectInput.java:245)
	... 7 more
@chrisco484
Copy link

chrisco484 commented Jul 21, 2019

I've been using FST for a few weeks now and it's awesome!

I just turned on G1GC garbage collection for the first time this morning and now I'm seeing this exception for the first time:

java.io.IOException: Failed to read the next byte

in heavily concurrent load testing so it is likely related to the bug reported on this page.

See my comment at #282

I'm hesitant to turn off G1GC because it is mandatory for String deduplication which I need turned on because my app processes user data which has millions of identical Strings.

Any progress on the bug?

@RuedigerMoeller
Copy link
Owner

RuedigerMoeller commented Jul 22, 2019

Thanks for your extensive report, unfortunately i am very busy. Anyways as FST is used in our current software I will investigate as soon as possible (TM).

@RuedigerMoeller
Copy link
Owner

If you run with java 8 its possible to turn off Unsafe Usage which will throw an exception instead of sigsev. Unfortunately Java 9 and higher forces use of Unsafe, though

@chrisco484
Copy link

chrisco484 commented Jul 25, 2019

@RuedigerMoeller As a workaround for the concurrent deserialization issue I'm thinking that I can just not use the stream from Conf that is designed for reuse and just create a new stream each time.

Does this sound reasonable, performance wise for my scenario? :

For one application I only ever have no more than about 3 objects that I serialize in one stream at any time. Presumably the reuse of existing stream was to save building up the class table/index each time but with only 3 classes in any stream that's probably not going to be an issue.

Presumably I can then have multiple streams taking place at the same time because they are not attempting to share a stream with a shared class table/index.

Right now I have to synchronize access to my deserialization methods to avoid the concurrency issue which is causing a massive performance bottleneck because, even though I only have 3 objects in the stream one of them can often be a many megabyte byte array.

@perlun
Copy link
Author

perlun commented Aug 29, 2019

@RuedigerMoeller

Thanks for your extensive report, unfortunately i am very busy. Anyways as FST is used in our current software I will investigate as soon as possible (TM).

Looking forward to that. 🙂 It's not the end of the world for us, we have FST (de)serialization behind a configuration flag for now and can easily re-enable it if/when this bug gets resolved.

If you run with java 8 its possible to turn off Unsafe Usage which will throw an exception instead of sigsev. Unfortunately Java 9 and higher forces use of Unsafe, though

We are still on Java 8, so disabling unsafe is possible. From what I've seen though, there are still some cases where FST uses unsafe operations even when unsafe is turned off. Quoting FSTUtil.java:

public static Unsafe unFlaggedUnsafe = FSTUtil.getUnsafe(); // even if unsafe is disabled, use it for memoffset computation

I cannot tell 100% for sure at this point if we've tried disabling unsafe in production or not (maybe @slovdahl remembers?), and if it made any difference re. the SIGSEGV errors. Anyhow, it would be nice with an option to disable all usage of unsafe, but I realize this might be asking for too much at the moment, especially if Java 9+ requires unsafe.

@rileyberton
Copy link

rileyberton commented Aug 25, 2020

This test case passes for me with the following changes to the test:

diff --git a/src/test/java/FSTSerializationTest.java b/src/test/java/FSTSerializationTest.java
index a1bf859..8b9bc2a 100644
--- a/src/test/java/FSTSerializationTest.java
+++ b/src/test/java/FSTSerializationTest.java
@@ -21,9 +21,9 @@ import org.testng.annotations.Test;
 // Test case, based on examples by @TheHound and @andrewl102
 public class FSTSerializationTest {

-    private final static int NUMBER_OF_THREADS = 16;
+    private final static int NUMBER_OF_THREADS = 32;

-    private final FSTConfiguration fstConf = FSTConfiguration.createDefaultConfiguration();
+    private ThreadLocal<FSTConfiguration> fstConf = ThreadLocal.withInitial(FSTConfiguration::createDefaultConfiguration);

     public static void main(String[] args) throws InterruptedException, ClassNotFoundException {
         new FSTSerializationTest().tryAndReProduceBug();
@@ -35,11 +35,11 @@ public class FSTSerializationTest {
         ExecutorService pool = Executors.newFixedThreadPool( NUMBER_OF_THREADS );

         // Pre-register classes to work around https://github.com/RuedigerMoeller/fast-serialization/issues/235
-        fstConf.registerClass( DateTime.class );
-        fstConf.registerClass( LocalDate.class );
-        fstConf.registerClass( Class.forName( "org.joda.time.chrono.ISOChronology$Stub" ) );
-        fstConf.registerClass( Class.forName( "org.joda.time.DateTimeZone$Stub" ) );
-        fstConf.registerClass( Class.forName( "FSTSerializationTest$TestObject" ) );
+        // fstConf.get().registerClass( DateTime.class );
+        // fstConf.get().registerClass( LocalDate.class );
+        // fstConf.get().registerClass( Class.forName( "org.joda.time.chrono.ISOChronology$Stub" ) );
+        // fstConf.get().registerClass( Class.forName( "org.joda.time.DateTimeZone$Stub" ) );
+        // fstConf.get().registerClass( Class.forName( "FSTSerializationTest$TestObject" ) );

         List<Future<?>> futures = new ArrayList<>();

@@ -71,7 +71,7 @@ public class FSTSerializationTest {
     }

     public Object readObject( final InputStream inputStream ) throws IOException {
-        try ( FSTObjectInput in = new FSTObjectInput( inputStream, fstConf ) ) {
+        try ( FSTObjectInput in = new FSTObjectInput( inputStream, fstConf.get() ) ) {
             return in.readObject();
         }
         catch ( Exception e ) {
@@ -80,7 +80,7 @@ public class FSTSerializationTest {
     }

     public void writeObject( final Object obj, final OutputStream outputStream ) throws IOException {
-        try ( FSTObjectOutput out = new FSTObjectOutput( outputStream, fstConf ) ) {
+        try ( FSTObjectOutput out = new FSTObjectOutput( outputStream, fstConf.get() ) ) {
             out.writeObject( obj );
         }
         catch ( Exception e ) {
@@ -99,4 +99,4 @@ public class FSTSerializationTest {

         private int inty = 129;
     }
-}
\ No newline at end of file
+}

Essentially, a ThreadLocal FSTConfiguration.

@theRealAph
Copy link

Should be fixed by #311 . Please check.

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

No branches or pull requests

5 participants