search

gotson / komga

Media server for comics/mangas/BDs/magazines/eBooks with API, OPDS and Kobo Sync support
https://komga.org
MIT License
3.89k stars 232 forks source link

Fatal error detected by JRE on initial start (Debian armv7l) #488

Closed robco closed 3 years ago

robco commented 3 years ago

Komga environment

Describe the bug

Komga is unable to start, A fatal error has been detected by the Java Runtime Environment.

Steps to reproduce

  1. Download komga.jar
  2. Execute by command "java -Xmx384m -jar komga-0.85.0.jar"

Expected behavior

Komga to start successfully

Actual behavior

2021-03-30 11:51:06.842  INFO 3624 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-03-30 11:51:08.094  INFO 3624 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGILL (0x4) at pc=0x95a00acc, pid=3624, tid=3625
#
# JRE version: OpenJDK Runtime Environment (11.0.9.1+1) (build 11.0.9.1+1-post-Debian-1deb10u2)
# Java VM: OpenJDK Server VM (11.0.9.1+1-post-Debian-1deb10u2, mixed mode, serial gc, linux-)
# Problematic frame:
# C  [webp-imageio-unknown-e015c1cd-cdc1-41c6-9725-209ea8a07495-libwebp-imageio.so+0x8acc]
#
# No core dump will be written. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /opt/komga/hs_err_pid3624.log
#
# If you would like to submit a bug report, please visit:
#   https://bugs.debian.org/openjdk-11
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#
Aborted

Launch console dump

$ java -Xmx384m -jar komga-0.85.0.jar 
 ____  __.
|    |/ _|____   _____    _________
|      < /  _ \ /     \  / ___\__  \
|    |  (  <_> )  Y Y  \/ /_/  > __ \_
|____|__ \____/|__|_|  /\___  (____  /
        \/           \//_____/     \/

Version: 0.85.0

2021-03-30 11:50:14.480  INFO 3624 --- [           main] org.gotson.komga.ApplicationKt           : Starting ApplicationKt using Java 11.0.9.1 on code-server with PID 3624 (/opt/komga/komga-0.85.0.jar started by coder in /opt/komga)
2021-03-30 11:50:14.574  INFO 3624 --- [           main] org.gotson.komga.ApplicationKt           : No active profile set, falling back to default profiles: default
2021-03-30 11:50:44.053  INFO 3624 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@a68df9' of type [org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2021-03-30 11:50:44.138  INFO 3624 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'methodSecurityMetadataSource' of type [org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2021-03-30 11:50:49.250  INFO 3624 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2021-03-30 11:50:49.409  INFO 3624 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-03-30 11:50:49.410  INFO 3624 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.43]
2021-03-30 11:50:50.052  INFO 3624 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2021-03-30 11:50:50.054  INFO 3624 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 34600 ms
2021-03-30 11:50:54.356  INFO 3624 --- [           main] o.s.b.a.e.web.ServletEndpointRegistrar   : Registered '/actuator/jolokia' to jolokia-actuator-endpoint
2021-03-30 11:50:54.919  INFO 3624 --- [           main] io.hawt.HawtioContextListener            : Initialising hawtio services
2021-03-30 11:50:55.479  INFO 3624 --- [           main] io.hawt.system.ConfigManager             : Configuration will be discovered via system properties
2021-03-30 11:50:55.489  INFO 3624 --- [           main] io.hawt.jmx.JmxTreeWatcher               : Welcome to Hawtio 2.13.0
2021-03-30 11:50:55.606  INFO 3624 --- [           main] i.h.w.auth.AuthenticationConfiguration   : Starting hawtio authentication filter, JAAS realm: "karaf" authorized role(s): "admin,manager,viewer" role principal classes: ""
2021-03-30 11:50:58.059  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221000: live Message Broker is starting with configuration Broker Configuration (clustered=false,journalDirectory=/home/coder/.komga/artemis/journal,bindingsDirectory=/home/coder/.komga/artemis/bindings,largeMessagesDirectory=/home/coder/.komga/artemis/largemessages,pagingDirectory=/home/coder/.komga/artemis/paging)
2021-03-30 11:50:58.387  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221013: Using NIO Journal
2021-03-30 11:50:59.055  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221057: Global Max Size is being adjusted to 1/2 of the JVM max size (-Xmx). being defined as 194,641,920
2021-03-30 11:50:59.180  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221043: Protocol module found: [artemis-server]. Adding protocol support for: CORE
2021-03-30 11:50:59.470  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601138: User anonymous@unknown is getting notification info on target resource: null []
2021-03-30 11:50:59.476  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.ActiveMQServerControlImpl@4ccef7 []
2021-03-30 11:50:59.478  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601138: User anonymous@unknown is getting notification info on target resource: ActiveMQServerImpl::serverUUID=274b8d5b-913c-11eb-8a42-0242ac110003 []
2021-03-30 11:50:59.838  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221034: Waiting indefinitely to obtain live lock
2021-03-30 11:50:59.840  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221035: Live Server Obtained live lock
2021-03-30 11:51:00.534  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AddressControlImpl@1a3f4de []
2021-03-30 11:51:00.545  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AddressControlImpl@1d2e270 []
2021-03-30 11:51:00.550  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AddressControlImpl@195105b []
2021-03-30 11:51:00.554  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AddressControlImpl@13e19b3 []
2021-03-30 11:51:00.985  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.QueueControlImpl@13a7ef5 []
2021-03-30 11:51:01.025  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.QueueControlImpl@851ce1 []
2021-03-30 11:51:01.059  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.QueueControlImpl@f6fd7f []
2021-03-30 11:51:02.157  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221080: Deploying address DLQ supporting [ANYCAST]
2021-03-30 11:51:02.198  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221003: Deploying ANYCAST queue DLQ on address DLQ
2021-03-30 11:51:02.274  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221080: Deploying address ExpiryQueue supporting [ANYCAST]
2021-03-30 11:51:02.276  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221003: Deploying ANYCAST queue ExpiryQueue on address ExpiryQueue
2021-03-30 11:51:02.279  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221003: Deploying ANYCAST queue tasks.background on address tasks.background
2021-03-30 11:51:02.712  INFO 3624 --- [           main] org.apache.activemq.audit.base           : AMQ601019: User anonymous@unknown is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AcceptorControlImpl@95416d []
2021-03-30 11:51:02.913  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221007: Server is now live
2021-03-30 11:51:02.914  INFO 3624 --- [           main] org.apache.activemq.artemis.core.server  : AMQ221001: Apache ActiveMQ Artemis Message Broker version 2.15.0 [localhost, nodeID=274b8d5b-913c-11eb-8a42-0242ac110003] 
2021-03-30 11:51:06.842  INFO 3624 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-03-30 11:51:08.094  INFO 3624 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGILL (0x4) at pc=0x95a00acc, pid=3624, tid=3625
#
# JRE version: OpenJDK Runtime Environment (11.0.9.1+1) (build 11.0.9.1+1-post-Debian-1deb10u2)
# Java VM: OpenJDK Server VM (11.0.9.1+1-post-Debian-1deb10u2, mixed mode, serial gc, linux-)
# Problematic frame:
# C  [webp-imageio-unknown-e015c1cd-cdc1-41c6-9725-209ea8a07495-libwebp-imageio.so+0x8acc]
#
# No core dump will be written. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /opt/komga/hs_err_pid3624.log
#
# If you would like to submit a bug report, please visit:
#   https://bugs.debian.org/openjdk-11
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#
Aborted

coder@code-server:/opt/komga$ uname -a
Linux code-server 4.14.22-armada-18.09.3 #1 SMP Mon Dec 21 02:42:49 UTC 2020 ga-18.09.3 Build-24 armv7l GNU/Linux
coder@code-server:/opt/komga$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 10 (buster)
Release:    10
Codename:   buster

Log file

hs_err_pid3624.log

gotson commented 3 years ago

Can you try with more ram in the Xmx?

robco commented 3 years ago

Hi @gotson, does not relate to memory setting.

gotson commented 3 years ago

Meaning you tried with more and it still crash?

robco commented 3 years ago

Indeed, tried with various memory settings, up to 1GB. This setting has no effect and still crashes with the same error.

gotson commented 3 years ago

Can you do a uname -m?

robco commented 3 years ago

$ uname -m armv7l

gotson commented 3 years ago

Like this I would say the webp native library for armv7 is not compatible with armv7l.

Any chance you could run it in docker to give a try?

robco commented 3 years ago

Already tried. Since docker is running on armv7l platform as well I am getting the same issue :/

gotson commented 3 years ago

I'm not sure I can fix the root cause, cross compiling for various hardware is quite difficult, but I could try to add a configuration flag to disable the loading of the native library, and fallback to the pure Java version.

Before I try though, given there is also the sqlite library which is native, could you try to open the jar, delete the webp jars inside (there should be 2), and try again with that modified jar?

Because if sqlite cannot run on your hardware there's nothing I will be able to do.

gotson commented 3 years ago

Probably related : https://github.com/gotson/komga/issues/398

robco commented 3 years ago

Just a note, the device I am trying to set this up, is WD My Cloud EX2 Ultra NAS. On NAS systems is armv7l is pretty common. Would be great if such architecture was supported but definitely undestand it is not easy to support multiple architectures.

@gotson, I am not sure how to modify JAR file, unfortunatelly all my attempts were not successful.

Btw. sqlite normally works on this NAS (installed via apt-get).

I've removed 2 JAR files from komga.jar (webp-imageio-0.2.0.jar, webp-imageio-decoder-plugin-0.2.jar) but unfortunatelly not able to run it since I am getting Error: Invalid or corrupt jarfile error message..

robco commented 3 years ago

I've seen #398 before I've filed this bug, but I do not particullary see any "sqlite errors" in my run log file..

gotson commented 3 years ago

I'll try to provide a modified jar for you soon so you can give it a try.

robco commented 3 years ago

I've just tried with jar -xvf komga.jar + delete webp + ``jar -cvf komga-patched.jar but now I am getting errorno main manifest attribute, in komga-patched.jar``. Seems it is not that trivial for me. Thank you for your support!

KasukeLp23 commented 3 years ago

In fact I get this problem also when trying to open komga on Windows and I get that fatal error.

Why is this problem? Because I wanted to try the program but I can't. I appreciate your help please

gotson commented 3 years ago

In fact I get this problem also when trying to open komga on Windows and I get that fatal error.

Why is this problem? Because I wanted to try the program but I can't. I appreciate your help please

Please open a separate issue and provide all the required information.

gotson commented 3 years ago

Just a note, the device I am trying to set this up, is WD My Cloud EX2 Ultra NAS. On NAS systems is armv7l is pretty common. Would be great if such architecture was supported but definitely undestand it is not easy to support multiple architectures.

I see that they have their own OS, MyCloud OS. But you mentioned Debian. Did you reinstall Debian on that? Or is MyCloud based on Debian?

robco commented 3 years ago

I am running multiple dockers on this machine, each "service" sandboxed. Base system is Debian as mentioned above.

gotson commented 3 years ago

I am running multiple dockers on this machine, each "service" sandboxed. Base system is Debian as mentioned above.

The webpage you pointed out does not mention Debian, it mentions MyCloud OS…

robco commented 3 years ago

MyCloud OS = BusyBox Linux. Which runs Docker Engine, in my case Docker v 19.03.8. Within docker I am able to run multiple instances, each instance can be based on different linux OS. In my case I am using Debian 10.

gotson commented 3 years ago

So you are running the jar within a container, container that is running in docker on mycloud os?

robco commented 3 years ago

What I've tried were 2 scenarios:

  1. Official Komga docker image => fials with the same error as above
  2. Debian 10 VM (in docker), installed Java + dependencies + run komga.jar within that => same error as with docker

Seems the issue is with the architecture armv7l since both cases are failing in the same way..

MyCloud OS5 is BusyBox Linux distribution with WebUI built on top of that where Docker engine is installed and enabling usage of different "VMs" using custom Linux OSes.

mihailim commented 3 years ago

@robco Does this still happen with the newly released 0.88.1, which replaces the native webp binaries with optimized Java implementations?

gotson commented 3 years ago

@robco Does this still happen with the newly released 0.88.1, which replaces the native webp binaries with optimized Java implementations?

It does not replace the native lib, it replaces a java lib with another java lib.

gotson commented 3 years ago

@robco could you try with this jar ? It will not load the native webp library automatically.

If that works fine, I will do a change in my fork of the native webp library wrapper to handle armv7l differently than armv7

robco commented 3 years ago

@mihailim, same issue with 0.88.1.

@gotson, seems I do not have access to this file in Google Drive. Just sent you a request for access. Thank you.

robco commented 3 years ago

Hi @gotson, seems your build made Komga to start, spin Tomcat and hook to my defined port (80) properly.

But as soon as I try to open the komga URL for the first time it crashes with error:

my run command: sudo java -jar komga-0.88.1-fix.jar --server.port=80

2021-04-27 08:10:56.968  INFO 25631 --- [           main] o.s.s.c.ThreadPoolTaskScheduler          : Initializing ExecutorService 'taskScheduler'
2021-04-27 08:10:59.541  INFO 25631 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 80 (http) with context path ''
2021-04-27 08:11:01.778  INFO 25631 --- [10003-24899729)] org.apache.activemq.audit.base           : AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::serverUUID=250d8585-a71f-11eb-a49e-0242ac110003 [with parameters: [576454fe-a71f-11eb-a49e-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=56d92bfb-a71f-11eb-a49e-0242ac110003, clientID=null, nodeID=250d8585-a71f-11eb-a49e-0242ac110003, transportConnection=InVMConnection [serverID=0, id=56d92bfb-a71f-11eb-a49e-0242ac110003]], false, false, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@dad3c2, true, OperationContextImpl [24996820] [minimalStore=9223372036854775807, storeLineUp=0, stored=0, minimalReplicated=9223372036854775807, replicationLineUp=0, replicated=0, paged=0, minimalPage=9223372036854775807, pageLineUp=0, errorCode=-1, errorMessage=null, executorsPending=0, executor=OrderedExecutor(tasks=[])], anonymous@invm:0]]
2021-04-27 08:11:02.285  INFO 25631 --- [10003-24899729)] org.apache.activemq.audit.base           : AMQ601267: User anonymous@invm:0 is creating a core session on target resource ActiveMQServerImpl::serverUUID=250d8585-a71f-11eb-a49e-0242ac110003 [with parameters: [57b88f7f-a71f-11eb-a49e-0242ac110003, null, ****, 102400, RemotingConnectionImpl [ID=56d92bfb-a71f-11eb-a49e-0242ac110003, clientID=null, nodeID=250d8585-a71f-11eb-a49e-0242ac110003, transportConnection=InVMConnection [serverID=0, id=56d92bfb-a71f-11eb-a49e-0242ac110003]], false, false, false, false, null, org.apache.activemq.artemis.core.protocol.core.impl.CoreSessionCallback@951d64, true, OperationContextImpl [3544700] [minimalStore=9223372036854775807, storeLineUp=0, stored=0, minimalReplicated=9223372036854775807, replicationLineUp=0, replicated=0, paged=0, minimalPage=9223372036854775807, pageLineUp=0, errorCode=-1, errorMessage=null, executorsPending=0, executor=OrderedExecutor(tasks=[])], anonymous@invm:0]]
2021-04-27 08:11:03.418  INFO 25631 --- [Impl$6@10a251b)] org.apache.activemq.audit.base           : AMQ601265: User null@invm:0 is creating a core consumer on target resource ServerSessionImpl(jms-session=*N/A*) [with parameters: [0, tasks.background, type = 'task', 0, false, true, null]]
2021-04-27 08:11:03.446  INFO 25631 --- [           main] org.gotson.komga.ApplicationKt           : Started ApplicationKt in 138.604 seconds (JVM running for 146.169)
2021-04-27 08:14:32.732  INFO 25631 --- [p-nio-80-exec-1] o.apache.coyote.http11.Http11Processor   : Error parsing HTTP request header
 Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.

java.lang.IllegalArgumentException: Invalid character found in method name [0x160x030x010x020x000x010x000x010xfc0x030x030xaa0xa8#G0xe40xe40xaad0xbd0x02i0xc1]. HTTP method names must be tokens
    at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:417) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:261) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:887) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1684) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.43.jar!/:9.0.43]
    at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]
gotson commented 3 years ago

HTTP method names must be tokens

Are you trying to access it via https ? A quick google search on your error seems to indicate that you are trying to use https instead of http.

robco commented 3 years ago

huh, that was it. I was explicitly opening http, but probably before Komga got booted Safari invisibly tried https. Now I can successfully create account and login to Komga!

gotson commented 3 years ago

Thanks for the report. I'll do the necessary changes in the webp library and deliver a new Komga release to fix your problem, so you can use mainline releases.

gotson commented 3 years ago

Before trying some changes on the webp library, i would like to test something within Komga to prevent loading the library via a configuration flag. That could come in handy later on for other people having the same kind of problem.

Could you try this jar:

robco commented 3 years ago

Hi there.

Just tried and can confim all worked as expected:

gotson commented 3 years ago

awesome, thanks for confirming. I'll ship that feature, and also try fixing the lib to disable it for armv7l.

gotson commented 3 years ago

@robco The new release will include 2 fixes:

github-actions[bot] commented 3 years ago

:tada: This issue has been resolved in version 0.89.2 :tada:

The release is available on:

Your semantic-release bot :package::rocket: