Illegal reflective access by org.springframework.boot.loader.jar.Handler

mja87 commented 4 years ago

Problem description

I'm a noob running Airsonic-Advanced through an OpenMediaVault docker, then through a Traefik 2 reverse proxy. 10.6 was working fine but something seems to have broken recently. The logs I see are below (first post on github, apologies if I screw something up):

Process will run as:,
User: 0,
Group: 0,
openjdk 14.0.1 2020-04-14,
OpenJDK Runtime Environment AdoptOpenJDK (build 14.0.1+7),
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 14.0.1+7, mixed mode, sharing),
JAVA_OPTS=,
ffmpeg version 4.2.2-1ubuntu1~18.04.york0 Copyright (c) 2000-2019 the FFmpeg developers,
built with gcc 7 (Ubuntu 7.5.0-3ubuntu1~18.04),
configuration: --prefix=/usr --extra-version='1ubuntu1~18.04.york0' --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-avresample --disable-filter=resample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librsvg --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-nvenc --enable-chromaprint --enable-frei0r --enable-libx264 --enable-shared,
libavutil      56. 31.100 / 56. 31.100,
libavcodec     58. 54.100 / 58. 54.100,
libavformat    58. 29.100 / 58. 29.100,
libavdevice    58.  8.100 / 58.  8.100,
libavfilter     7. 57.100 /  7. 57.100,
libavresample   4.  0.  0 /  4.  0.  0,
libswscale      5.  5.100 /  5.  5.100,
libswresample   3.  5.100 /  3.  5.100,
libpostproc    55.  5.100 / 55.  5.100,
curl 7.58.0 (x86_64-pc-linux-gnu) libcurl/7.58.0 OpenSSL/1.1.1 zlib/1.2.11 libidn2/2.0.4 libpsl/0.19.1 (+libidn2/2.0.4) nghttp2/1.30.0 librtmp/2.3,
Release-Date: 2018-01-24,
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp smb smbs smtp smtps telnet tftp ,
Features: AsynchDNS IDN IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz TLS-SRP HTTP2 UnixSockets HTTPS-proxy PSL ,
PATH=/opt/java/openjdk/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin,
LOGBACK: No context given for c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@502800944,
           _                       _          ,
     /\   (_)                     (_)         ,
    /  \   _ _ __  ___  ___  _ __  _  ___     ,
   / /\ \ | | '__|/ __|/ _ \| '_ \| |/ __|    ,
  / ____ \| | |   \__ \ (_) | | | | | (__     ,
 /_/    \_\_|_|   |___/\___/|_| |_|_|\___|    ,
                                               ,
                        11.0.0-SNAPSHOT,
,
,
,
2020-05-04 15:42:01.947  INFO --- org.airsonic.player.Application          : Starting Application v11.0.0-SNAPSHOT on 1cb093a700a8 with PID 7 (/var/airsonic.war started by root in /var),
2020-05-04 15:42:01.967  INFO --- org.airsonic.player.Application          : No active profile set, falling back to default profiles: default,
2020-05-04 15:42:08.386  INFO --- l.executor.jvm.JdbcExecutor              : SELECT COUNT(*) FROM PUBLIC.DATABASECHANGELOGLOCK,
2020-05-04 15:42:08.395  INFO --- l.executor.jvm.JdbcExecutor              : SELECT COUNT(*) FROM PUBLIC.DATABASECHANGELOGLOCK,
2020-05-04 15:42:08.416  INFO --- l.l.StandardLockService                  : Successfully acquired change log lock,
2020-05-04 15:42:11.408  INFO --- l.executor.jvm.JdbcExecutor              : SELECT MD5SUM FROM PUBLIC.DATABASECHANGELOG WHERE MD5SUM IS NOT NULL,
2020-05-04 15:42:11.415  INFO --- l.executor.jvm.JdbcExecutor              : SELECT COUNT(*) FROM PUBLIC.DATABASECHANGELOG,
2020-05-04 15:42:11.417  INFO --- l.c.StandardChangeLogHistoryService      : Reading from PUBLIC.DATABASECHANGELOG,
2020-05-04 15:42:11.418  INFO --- l.executor.jvm.JdbcExecutor              : SELECT * FROM PUBLIC.DATABASECHANGELOG ORDER BY DATEEXECUTED ASC, ORDEREXECUTED ASC,
2020-05-04 15:42:11.667  INFO --- l.l.StandardLockService                  : Successfully released change log lock,
2020-05-04 15:42:11.669  INFO --- l.executor.jvm.JdbcExecutor              : SELECT COUNT(*) FROM PUBLIC.DATABASECHANGELOGLOCK,
2020-05-04 15:42:11.670  INFO --- l.executor.jvm.JdbcExecutor              : SELECT COUNT(*) FROM PUBLIC.DATABASECHANGELOGLOCK,
2020-05-04 15:42:11.671  INFO --- l.executor.jvm.JdbcExecutor              : SELECT LOCKED FROM PUBLIC.DATABASECHANGELOGLOCK WHERE ID=1,
2020-05-04 15:42:11.691  INFO --- l.l.StandardLockService                  : Successfully acquired change log lock,
2020-05-04 15:42:11.739  INFO --- l.executor.jvm.JdbcExecutor              : SELECT MD5SUM FROM PUBLIC.DATABASECHANGELOG WHERE MD5SUM IS NOT NULL,
2020-05-04 15:42:11.741  INFO --- l.executor.jvm.JdbcExecutor              : SELECT COUNT(*) FROM PUBLIC.DATABASECHANGELOG,
2020-05-04 15:42:11.742  INFO --- l.c.StandardChangeLogHistoryService      : Reading from PUBLIC.DATABASECHANGELOG,
2020-05-04 15:42:11.743  INFO --- l.executor.jvm.JdbcExecutor              : SELECT * FROM PUBLIC.DATABASECHANGELOG ORDER BY DATEEXECUTED ASC, ORDEREXECUTED ASC,
2020-05-04 15:42:11.769  INFO --- l.l.StandardLockService                  : Successfully released change log lock,
2020-05-04 15:42:11.909  INFO --- o.a.p.service.SettingsService            : Java: 14.0.1, OS: Linux,
2020-05-04 15:42:12.036  INFO --- org.airsonic.player.Application          : Detected Tomcat web server,
WARNING: An illegal reflective access operation has occurred,
WARNING: Illegal reflective access by org.springframework.boot.loader.jar.Handler (file:/var/airsonic.war) to constructor sun.net.www.protocol.jar.Handler(),
WARNING: Please consider reporting this to the maintainers of org.springframework.boot.loader.jar.Handler,
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,
2020-05-04 15:42:17.545  INFO --- o.a.p.s.search.IndexManager              : Index was found (index version 18). ,
2020-05-04 15:42:17.549  INFO --- o.a.p.s.MediaScannerService              : Automatic media library scanning scheduled to run every 1 day(s), starting at 2020-05-05T03:00:00.548511,
2020-05-04 15:42:18.497  INFO --- o.a.p.service.PodcastService             : Automatic Podcast update scheduled to run every 24 hour(s), starting at 2020-05-04T15:47:18.496746Z,
2020-05-04 15:42:22.297  INFO --- org.airsonic.player.Application          : Started Application in 22.875 seconds (JVM running for 23.899),
2020-05-04 15:47:18.496  INFO --- o.a.p.service.PodcastService             : Starting scheduled Podcast refresh.,
2020-05-04 15:47:18.500  INFO --- o.a.p.service.PodcastService             : Completed scheduled Podcast refresh.,

Steps to reproduce

See that container is listed as "unhealthy" in Portainer
Restart container
Goes back to "unhealthy"

System information

Airsonic version: v11.0.0-SNAPSHOT
Operating system: OpenMediaVault (Debian based NAS operating system)
Java version: According to the logs I think its 14.0.1?
Proxy server: Traefik 2.0
Client: Firefox
Language: English

Additional notes

I'm a gigantic noob to all of this, but I've really enjoyed your project and appreciate any help.

randomnicode commented 4 years ago

Hmmm, I think the healthcheck might be broken because this issue of the container appearing unhealthy has been raised before... We might have to try a different healthcheck...

However this error is actually NOT an issue, it's a red herring... just something Java complains about Spring. It's relatively harmless (for now)

WARNING: An illegal reflective access operation has occurred,
WARNING: Illegal reflective access by org.springframework.boot.loader.jar.Handler (file:/var/airsonic.war) to constructor sun.net.www.protocol.jar.Handler(),
WARNING: Please consider reporting this to the maintainers of org.springframework.boot.loader.jar.Handler,
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,

In short, I think the container is fine, even if it appears unhealthy

mja87 commented 4 years ago

You're absolutely right, I can connect to -my nas IP-:4040 and it comes right up. I guess I saw the error in the logs and got a 404 when trying to go to music.-mydomain-.com and erroneously connected the two, sorry about that.

It looks like it must be yet another problem with my reverse proxy set up. I guess I get to spend more hours banging my head against the Traefik wall. It doesn't even feel worth it any more!

Thanks for your help.

BobWs commented 4 years ago

Having the same warning in my Log. I installed this image on docker Synology.

2020-05-05 11:46:31.462 INFO --- org.airsonic.player.Application : Detected Tomcat web server stdout 09:46:39 WARNING: An illegal reflective access operation has occurred stdout 09:46:39 WARNING: Illegal reflective access by org.springframework.boot.loader.jar.Handler (file:/var/airsonic.war) to constructor sun.net.www.protocol.jar.Handler() stdout 09:46:39 WARNING: Please consider reporting this to the maintainers of org.springframework.boot.loader.jar.Handler stdout 09:46:39 WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations stdout 09:46:39 WARNING: All illegal access operations will be denied in a future release stdout 09:46:45 2020-05-05 11:46:45.167 WARN --- o.a.p.s.GlobalSecurityConfig : Generating new encryption key password stdout 09:46:45 Reverse proxy works fine for me!

BobWs commented 4 years ago

You're absolutely right, I can connect to :4040 and it comes right up. I guess I saw the error in the logs and got a 404 when trying to go to music..com and erroneously connected the two, sorry about that.

It looks like it must be yet another problem with my reverse proxy set up. I guess I get to spend more hours banging my head against the Traefik wall. It doesn't even feel worth it any more!

Thanks for your help.

Have you tried to add this to your airsonic.properties file? server.use-forward-headers=true That did the trick for me to get reverse proxy working.

randomnicode commented 4 years ago

This is a good point, perhaps it should be incorporated out of the box.

Note that the property is deprecated: server.use-forward-headers=true and is replaced by: server.forward-headers-strategy=framework or server.forward-headers-strategy=native

foobazbar123 commented 4 years ago

Please do make that out of the box. I just spent three hours to finally stumble upon this right before giving up on Airsonic Advanced entirely

airsonic-advanced / airsonic-advanced