Java error in version 2.0.0

[chrishuges]

Hi,

I am seeing an error in PeptideShaker 2.0.0.

Sat Nov 07 14:05:13 PST 2020 PeptideShaker process completed.
Sat Nov 07 14:05:13 PST 2020 Processing Completed.
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.esotericsoftware.kryo.unsafe.UnsafeUtil (file:/projects/ptx_analysis/chughes/software/PeptideShaker-2.0.0/lib/kryo-5.0.0-RC9.jar) to method sun.nio.ch.DirectBuffer.cleaner()
WARNING: Please consider reporting this to the maintainers of com.esotericsoftware.kryo.unsafe.UnsafeUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Sat Nov 07 14:05:45 PST 2020 Exporting. Please Wait...
10% 20% 30% 40% 50% 60% 70% 80% 90%#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007f840d82c0d4, pid=24451, tid=24452
#
# JRE version: Java(TM) SE Runtime Environment (15.0.1+9) (build 15.0.1+9-18)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (15.0.1+9-18, mixed mode, sharing, tiered, g1 gc, linux-amd64)
# Problematic frame:
# C  [sqlite-3.18.0-b9e8c7da-2323-440e-91eb-0641b955ced7-libsqlitejdbc.so+0x100d4]
#
# Core dump will be written. Default location: Core dumps may be processed with "/usr/libexec/abrt-hook-ccpp %s %c %p %u %g %t e %P %I %h" (or dumping to /projects/ptx_results/2020/Eclipse/11-Nov/Samples/CH/dataProcessing_20201106_SonyaTranslationSet1_silac10R8K-TMT10_HpH/core.24451)
#
# An error report file with more information is saved as:
# /projects/ptx_results/2020/Eclipse/11-Nov/Samples/CH/dataProcessing_20201106_SonyaTranslationSet1_silac10R8K-TMT10_HpH/hs_err_pid24451.log
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#
./rawDataProcessing_m16tmt11silack8r10CidItHumanTrypsinCombined.sh: line 180: 24451 Aborted                 (core dumped) /gsc/software/linux-x86_64-centos7/jdk-15.0.1/bin/java -Xmx120g -cp /projects/ptx_analysis/chughes/software/PeptideShaker-2.0.0/PeptideShaker-2.0.0.jar eu.isas.peptideshaker.cmd.ReportCLI -in 20201106_SonyaTranslationSet1_silac10R8K-TMT10_HpH.out.psdb -out_reports /projects/ptx_results/2020/Eclipse/11-Nov/Samples/CH/dataProcessing_20201106_SonyaTranslationSet1_silac10R8K-TMT10_HpH -reports 0,3

PeptideShaker seems to finish fine and then Reports is triggered to output the Certificate of Analysis and the Default PSM Report, which is when this error is triggered. But, it seems to actually write the reports OK as far as I can tell, although I am not entirely sure if it writes the entire PSM report (this gets export second).

Let me know if you need more information.

Thanks,
Chris

[hbarsnes]

Hi Chris,

This looks more like a Java stability issue than an issue within the PeptideShaker code? We've been using Java 14 for some time and have not come across similar issues there. Is the error reproducible or did it only happen this one time?

Best regards,
Harald

[chrishuges]

Hi Harald,

I moved to Java 14 and don't see the issue anymore.

Cheers,
Chris

[hbarsnes]

Great! Thanks for the update! I will then close the issue and we can hope that a more stable Java 15 (or newer) will become available in the future.

[veitveit]

Same problem for different PeptideShaker version (e.g. 2.0.15 and 2.0.30) and OpenJDK java versions 11.0.9.1-internal and 1.8.0_292. I got this problem initially in the latest conda packages of PeptideShaker and then tried the manually installed versions on the same Linux machine.
hs_err_pid16304.log
The command was
java -cp /opt/PeptideShaker-2.0.30/PeptideShaker-2.0.30.jar eu.isas.peptideshaker.cmd.ReportCLI -in ./Non-mod_a_peptide_out.psdb -reports 4 -out_reports ./
It actually writes the PSM file but I am not sure whether it is complete.
You can download the psdb file from here: http://computproteomics.bmb.sdu.dk/tmp/Non-mod_a_peptide_out.psdb

@hbarsnes Any idea of how to avoid this error?

[hbarsnes]

@veitveit Any chance you can update to Java 14 or 15 as well? (Java 16 has some other issues at the moment...)

[veitveit]

Sorry, I got a similar error with Java 15 (openjdk version "15.0.2" 2021-01-19)

# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007f9a9d9fd0d4, pid=3976, tid=3977
#
# JRE version: OpenJDK Runtime Environment AdoptOpenJDK (15.0.2+7) (build 15.0.2+7)
# Java VM: OpenJDK 64-Bit Server VM AdoptOpenJDK (15.0.2+7, mixed mode, sharing, tiered, compressed oops, g1 gc, linux-amd64)
# Problematic frame:
# C  [sqlite-3.18.0-c798d5a8-7457-49af-9002-c2f4709d8896-libsqlitejdbc.so+0x100d4]
#
# Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P %E" (or dumping to /home/veit/IsoPTMProt/work/f8/35c021698c6fd95d5f96b90edb64c4/core.3976)
#
# An error report file with more information is saved as:
# /home/veit/IsoPTMProt/work/f8/35c021698c6fd95d5f96b90edb64c4/hs_err_pid3976.log
Compiled method (n/a) 2145672 3025  s  n 0       org.sqlite.core.NativeDB::finalize (native)
 total in heap  [0x00007f9b03fbde10,0x00007f9b03fbe260] = 1104
 relocation     [0x00007f9b03fbdf68,0x00007f9b03fbdfa0] = 56
 main code      [0x00007f9b03fbdfa0,0x00007f9b03fbe258] = 696
 oops           [0x00007f9b03fbe258,0x00007f9b03fbe260] = 8
#
# If you would like to submit a bug report, please visit:
#   https://github.com/AdoptOpenJDK/openjdk-support/issues
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#
Aborted (core dumped)

[hbarsnes]

@veitveit Given that Java 14 seemed to work for Chris, maybe you can give that version a go as well?

[veitveit]

@hbarsnes And here it, seems to be the same problem:

/usr/lib/jvm/adoptopenjdk-14-openj9-jre-amd64/bin/java -cp /opt/PeptideShaker-2.0.30/PeptideShaker-2.0.30.jar eu.isas.peptideshaker.cmd.ReportCLI -in ./Non-mod_a_peptide_out.psdb -reports 4 -out_reports ./
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.esotericsoftware.kryo.unsafe.UnsafeUtil (file:/opt/PeptideShaker-2.0.30/lib/kryo-5.0.0-RC9.jar) to method sun.nio.ch.DirectBuffer.cleaner()
WARNING: Please consider reporting this to the maintainers of com.esotericsoftware.kryo.unsafe.UnsafeUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Thu Jun 03 15:53:10 CEST 2021 Exporting. Please Wait...
10% 20% 30% 40% 50% 60% 70% 80% 90%^[[B^[[A^[[A^[[B^[[A^[[B^[[AUnhandled exception
Type=Segmentation error vmState=0x00000000
J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
Handler1=00007FE0084FB0F0 Handler2=00007FE003DA4A60 InaccessibleAddress=0000000000000018
RDI=00007FE0049AD9C0 RSI=0000000000000001 RAX=0000000000000000 RBX=00007FE0040EA938
RCX=00007FE00406E968 RDX=0000000000000018 R8=00007FE0049AD9C0 R9=00000001C9C13450
R10=0000000000126E08 R11=00007FDECE7EC2E0 R12=00007FE0040514F8 R13=00007FE00455FA68
R14=00007FDE80EEB288 R15=00007FE0045AFBA8
RIP=00007FDECE7EC0D4 GS=0000 FS=0000 RSP=00007FE0094377C8
EFlags=0000000000010283 CS=0033 RBP=00007FDE80EEBCD8 ERR=0000000000000004
TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=0000000000000018
xmm0 00007fde80eeb288 (f: 2163127040.000000, d: 6.946248e-310)
xmm1 00007fde80eeb288 (f: 2163127040.000000, d: 6.946248e-310)
xmm2 00007fe0094378e0 (f: 155416800.000000, d: 6.946573e-310)
xmm3 6f6d656d2f656369 (f: 795173760.000000, d: 5.571061e+228)
xmm4 475645414d4c2d51 (f: 1296838016.000000, d: 4.625408e+35)
xmm5 4b47463e6d6d633c (f: 1835885312.000000, d: 4.458487e+54)
xmm6 29353228204d2066 (f: 541925504.000000, d: 3.525445e-110)
xmm7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm8 565f726f72724500 (f: 1920091392.000000, d: 1.153979e+108)
xmm9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm10 3ff00dbdcd6a2670 (f: 3446285824.000000, d: 1.003355e+00)
xmm11 402a01b7b9ad44ce (f: 3115140352.000000, d: 1.300335e+01)
xmm12 408a3bb100000000 (f: 0.000000, d: 8.394614e+02)
xmm13 408a3bb100000000 (f: 0.000000, d: 8.394614e+02)
xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm15 40f6b5ecc098220d (f: 3231195648.000000, d: 9.302280e+04)
Module=/tmp/sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so
Module_base_address=00007FDECE7DC000
Target=2_90_20200715_149 (Linux 4.15.0-134-generic)
CPU=amd64 (48 logical CPUs) (0x2f25903000 RAM)
----------- Stack Backtrace -----------
(0x00007FDECE7EC0D4 [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x100d4])
(0x00007FDECE83895D [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x5c95d])
(0x00007FDECE838CAD [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x5ccad])
(0x00007FDECE8568D5 [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x7a8d5])
(0x00007FDECE856A22 [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x7aa22])
(0x00007FDECE857381 [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x7b381])
(0x00007FDECE857518 [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x7b518])
(0x00007FDECE8576E0 [sqlite-3.18.0-4e32dea9-e57e-4c56-b1d2-419845055fb5-libsqlitejdbc.so+0x7b6e0])
(0x00007FDFCBC9A8D0 [<unknown>+0x0])
---------------------------------------
JVMDUMP039I Processing dump event "gpf", detail "" at 2021/06/03 16:30:19 - please wait.
JVMDUMP032I JVM requested System dump using '/home/veit/IsoPTMProt/work/f8/35c021698c6fd95d5f96b90edb64c4/core.20210603.163019.10296.0001.dmp' in response to an event

[hbarsnes]

@veitveit Can you try giving PeptideShaker more memory to work with? In other words, adding the -Xmx option to your command line?

[veitveit]

@hbarsnes No change with -Xmx32G. I will try now with 50GB but have my doubts that is will go through.
Did you try writing the file on one of your computers?

[hbarsnes]

@veitveit Yes, the exports all work fine on my side. Hence the problem of how to debug the issue...

[veitveit]

@hbarsnes I am trying it with java 14 on another machine now.
As the problem appears with the conda package, can you try to run PeptideShaker via conda. This is the environment file I used:

name: isobar_ptm
channels:
  - defaults
  - bioconda
  - conda-forge
dependencies:
  - thermorawfileparser=1.3.4
  - searchgui=4.0.33
  - peptide-shaker=2.0.25
  - unzip=6.0 
  - bioconductor-msnbase=2.14.1

I additionally installed this conda environment on a docker image, but this might not be necessary

[veitveit]

Update: same failure on another linux machine

Odd situation that I don't manage to make it work and you always :-D

java -Xmx50G -cp /tmp/PeptideShaker-2.0.30/PeptideShaker-2.0.30.jar eu.isas.peptideshaker.cmd.ReportCLI -in /tmp/test/Non-mod_a_peptide_out.psdb -reports 4 -out_reports ./
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by com.esotericsoftware.kryo.unsafe.UnsafeUtil (file:/tmp/PeptideShaker-2.0.30/lib/kryo-5.0.0-RC9.jar) to method sun.nio.ch.DirectBuffer.cleaner()
WARNING: Please consider reporting this to the maintainers of com.esotericsoftware.kryo.unsafe.UnsafeUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
10% 20% 30% 40% 50% 60% 70% 80% 90% 100%
Fri Jun 04 14:28:41 CEST 2021 Exporting. Please Wait...
10% 20% 30% 40% 50% 60% 70% 80% 90%^[[A^[[B^[[B^[[A#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007fb5cf0110d4, pid=86229, tid=86230
#
# JRE version: OpenJDK Runtime Environment (14.0.2+12) (build 14.0.2+12-Ubuntu-120.04)
# Java VM: OpenJDK 64-Bit Server VM (14.0.2+12-Ubuntu-120.04, mixed mode, tiered, g1 gc, linux-amd64)
# Problematic frame:
# C  [sqlite-3.18.0-316528b4-e06f-4614-a0be-fa40d6656e70-libsqlitejdbc.so+0x100d4]
#
# Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P %E" (or dumping to /tmp/test/core.86229)
#
# An error report file with more information is saved as:
# /tmp/test/hs_err_pid86229.log
#
# If you would like to submit a bug report, please visit:
#   Unknown
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

[hbarsnes]

@veitveit Maybe the reason is that I only tested the exports with the example dataset so far. I can try with your data as well, but then I would need your FASTA and spectrum files too.

[veitveit]

@hbarsnes
It is definitely this data sets as I successfully extracted quite many other reports. The spectrum files and the fasta are on http://computproteomics.bmb.sdu.dk/tmp/FailedRun.zip

Thank you!

[hbarsnes]

@veitveit I can confirm that I get the same Java error for this particular data set as well. I will try to dig deeper and see what I can find. Might be a bit tricky as the error seems to occur inside SQLite though...

[hbarsnes]

@veitveit Quick update: We've now released a new version of PeptideShaker that also works on Java 16, but sadly upgrading to Java 16 does not make any difference on my end. But perhaps you can give it another go on your setup with Java 16 anyway?

[veitveit]

@hbarsnes Great that PeptideShaker now also works with Java 16. I also get still the same error.

[hbarsnes]

@veitveit Ah, that's too bad. But not unexpected of course. I guess we'll just have to wait for Java 17 then..? ;)

[veitveit]

@hbarsnes

Could the problem come from the version of the sqlite-jdbc library? There are much newer ones than version 3.18.

And my experience is that java libraries are not really a gem of compatibility

[hbarsnes]

@veitveit I assumed that we were using the latest version of the sqlite-jdbc library, but if that is indeed not the case I will try updating and get back to you.

[hbarsnes]

@veitveit Updating to the most recent version of the sqlite-jdbc library does not seem to make a difference. However, the export works fine if done from the GUI instead of from the command line. And the resulting export from the GUI has the same file size and the same number of rows (with just the order of a couple of lines being switched) as the one from the command line that ends in the fatal Java error. I think we can therefore conclude that the export (at least in this case) has completed before the Java error occurs, but I will have to investigate this further.

[hbarsnes]

@veitveit Just noticed that the Java error is also there when exporting via the GUI as well. It is just not highlighted in the same way (as it is basically just written to the same folder as we jar file). So at least the error is consistent...

[veitveit]

@hbarsnes Let's say I am not interested too much in the error. Is there a way to find out whether the output file is actually complete?

[hbarsnes]

@veitveit I was trying to look into that. Given that the export in the GUI completes successfully, and the error only occurs afterwards, I think the output file is complete. But whether the data in the database has been corrupted along the way and thus affecting the output I cannot be sure. I do not think so though, as then there ought to have been "normal" Java exceptions in our own code when extracting the information.