Bug 1755634 - After upgrading to Fedore 31, PKI web UI use results in server error 500 w/ Java stacktrace
Summary: After upgrading to Fedore 31, PKI web UI use results in server error 500 w/ J...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: pki-core
Version: 31
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: Alex Scheel
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-09-25 21:56 UTC by Arno Lehmann
Modified: 2020-11-24 20:00 UTC (History)
8 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2020-11-24 20:00:10 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
/var/lib/pki/pki-tomcat/conf/catalina.policy (20.96 KB, text/x-csrc)
2019-11-04 22:32 UTC, Patrick Dung
no flags Details

Description Arno Lehmann 2019-09-25 21:56:55 UTC
Description of problem:

accessing the PKI web ui results in server error 500 as soon as the java middleware is involved. Stack traces are in debug logs and web site.

I'm neither enough of a Java person nor a PKI expert to understand what's actually broken.


Version-Release number of selected component (if applicable):

[root@ca2 ~]# rpm -qa | grep 'pki-'
dogtag-pki-server-theme-10.7.3-3.fc31.noarch
pki-base-10.7.3-3.fc31.noarch
pki-server-10.7.3-3.fc31.noarch
pki-ca-10.7.3-3.fc31.noarch
pki-console-10.7.3-3.fc31.noarch
python3-pki-10.7.3-3.fc31.noarch
pki-tools-10.7.3-3.fc31.x86_64
pki-symkey-10.7.3-3.fc31.x86_64
pki-kra-10.7.3-3.fc31.noarch
pki-ocsp-10.7.3-3.fc31.noarch
pki-base-java-10.7.3-3.fc31.noarch
dogtag-pki-console-theme-10.7.3-3.fc31.noarch

How reproducible:

Not confirmed, but I suspect any similar installation will show the describedbehaviour. In particular, upgrade a rather minimal nd straight-forward pki instance from fedore 30 to 31, and access the web UI.


Then:

Web interface contents when accssing https://ca2.<redacted>.de:8443/pki/ui/

HTTP Status 500 – Internal Server Error

Type Exception Report

Message org.apache.jasper.JasperException: Unable to compile class for JSP

Beschreibung The server encountered an unexpected condition that prevented it from fulfilling the request.

Exception

org.apache.jasper.JasperException: org.apache.jasper.JasperException: Unable to compile class for JSP
	org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:604)
	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:422)
	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:385)
	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:329)
	javax.servlet.http.HttpServlet.service(HttpServlet.java:741)



In the trace file:
[root@ca2 ~]# tail -n 71 /var/lib/pki/CA2/logs/pki/debug.2019-09-25.log
2019-09-25 23:46:36 [https-jsse-nio-8443-exec-1] SEVERE: Servlet.service() for servlet [jsp] in context with path [/pki] threw exception [org.apache.jasper.JasperException: Unable to compile class for JSP] with root cause
java.security.AccessControlException: access denied ("java.util.PropertyPermission" "tolerateIllegalAmbiguousVarargsInvocation" "read")
	at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
	at java.security.AccessController.checkPermission(AccessController.java:886)
	at java.lang.SecurityManager.checkPermission(SecurityManager.java:549)
	at java.lang.SecurityManager.checkPropertyAccess(SecurityManager.java:1294)
	at java.lang.System.getProperty(System.java:717)
	at org.eclipse.jdt.internal.compiler.impl.CompilerOptions.<init>(CompilerOptions.java:513)
	at org.apache.jasper.compiler.JDTCompiler.generateClass(JDTCompiler.java:483)
	at org.apache.jasper.compiler.Compiler.compile(Compiler.java:392)
	at org.apache.jasper.compiler.Compiler.compile(Compiler.java:362)
	at org.apache.jasper.compiler.Compiler.compile(Compiler.java:346)
	at org.apache.jasper.JspCompilationContext.compile(JspCompilationContext.java:603)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:399)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:385)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:329)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	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.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:225)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	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.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:253)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:191)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:607)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:678)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:853)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)



Service status is this:
[root@ca2 ~]# systemctl status pki-tomcatd | cat
+● pki-tomcatd - PKI Tomcat Server CA2
   Loaded: loaded (/usr/lib/systemd/system/pki-tomcatd@.service; enabled; vendor preset: disabled)
   Active: active (running) since Mon 2019-09-23 16:47:58 CEST; 2 days ago
 Main PID: 22189 (java)
    Tasks: 102
   Memory: 192.0M
      CPU: 5min 20.216s
   CGroup: /system.slice/system-pki\x2dtomcatd.slice/pki-tomcatd
           └─22189 /usr/lib/jvm/jre-1.8.0-openjdk/bin/java -Djava.library.path=/usr/lib64/nuxwdog-jni -classpath /usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/lib/java/commons-daemon.jar -Dcatalina.base=/var/lib/pki/CA2 -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/CA2/temp -Djava.util.logging.config.file=/var/lib/pki/CA2/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.security.manager -Djava.security.policy==/var/lib/pki/CA2/conf/catalina.policy org.apache.catalina.startup.Bootstrap start

Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:932)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at org.apache.catalina.startup.Catalina.start(Catalina.java:633)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at java.lang.reflect.Method.invoke(Method.java:498)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:344)
Sep 23 16:48:10 ca2.<redacted>.de server[22189]:         at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:475)



The whole system is up to date:
[root@ca2 ~]# LANG=C dnf up
Last metadata expiration check: 0:00:43 ago on Wed Sep 25 23:53:10 2019.
Dependencies resolved.
Nothing to do.
Complete!



Sidenote: I never used or even thoroughly dug through any fedora bug report, so if I used the wrong place to report this issue, I'd be grateful for a detailed, not short, set of directions :-)


Cheers,

Arno

Comment 1 Patrick Dung 2019-11-04 19:25:13 UTC
Hello,

Any news regarding this bug?
I had upgraded from FC30 to FC31 and having the same problem too.

Comment 2 Endi Sukma Dewata 2019-11-04 20:13:32 UTC
Hi, could you check the upgrade logs in /var/log/pki/pki-server-upgrade-*,
are there any failures?

Could you also try setting SECURITY_MANAGER="false" in both of these files?
* /etc/sysconfig/pki-tomcat
* /etc/pki/pki-tomcat/tomcat.conf
Then restart the server.

Thanks.

Comment 3 Patrick Dung 2019-11-04 20:59:46 UTC
For my case:
/var/log/pki/pki-server-upgrade-* looks fine for the upgrade.
After setting SECURITY_MANAGER=false in those files, the pki-tomcat can startup and the CA function looks okay now.

Comment 4 Endi Sukma Dewata 2019-11-04 21:56:27 UTC
Thanks, Patrick.

The AccessControlException was triggered when the Eclipse JDT tried
to read a system property. The permission for that should have been
configured in /var/lib/pki/pki-tomcat/conf/catalina.policy, but for
some reason it no longer works. Could you attach the catalina.policy?

Could you also provide the output of these commands?
$ ls -la /var/lib/pki/pki-tomcat/
$ ls -la /var/lib/pki/pki-tomcat/common/

Thanks.

Comment 5 Patrick Dung 2019-11-04 22:32:07 UTC
Created attachment 1632776 [details]
/var/lib/pki/pki-tomcat/conf/catalina.policy

/var/lib/pki/pki-tomcat/conf/catalina.policy

Comment 6 Patrick Dung 2019-11-04 22:33:40 UTC
The policy was attached and the directory listing is in below. Thanks.

# ls -la /var/lib/pki/pki-tomcat/
total 24
drwxrwx---. 6 pkiuser pkiuser 4096 Oct  5 21:15 .
drwxr-xr-x. 3 root    root    4096 Aug 15 09:04 ..
lrwxrwxrwx. 1 pkiuser pkiuser   25 Aug 26  2018 alias -> /etc/pki/pki-tomcat/alias
lrwxrwxrwx. 1 pkiuser pkiuser   21 Aug 26  2018 bin -> /usr/share/tomcat/bin
drwxrwx---. 5 pkiuser pkiuser 4096 Aug 26  2018 ca
lrwxrwxrwx. 1 pkiuser pkiuser   28 Aug 26  2018 common -> /usr/share/pki/server/common
lrwxrwxrwx. 1 pkiuser pkiuser   19 Aug 26  2018 conf -> /etc/pki/pki-tomcat
lrwxrwxrwx. 1 pkiuser pkiuser   25 Oct  5 21:15 lib -> /usr/share/pki/server/lib
lrwxrwxrwx. 1 pkiuser pkiuser   23 Aug 26  2018 logs -> /var/log/pki/pki-tomcat
lrwxrwxrwx. 1 root    root      16 Aug 26  2018 pki-tomcat -> /usr/sbin/tomcat
drwxrwx---. 2 pkiuser pkiuser 4096 Aug 26  2018 temp
drwxr-xr-x. 2 pkiuser pkiuser 4096 Aug 26  2018 webapps
drwxrwx---. 3 pkiuser pkiuser 4096 Aug 26  2018 work

# ls -la /var/lib/pki/pki-tomcat/common/
total 12
drwxr-xr-x 3 root root 4096 Aug 15 09:04 .
drwxr-xr-x 9 root root 4096 Aug 15 09:04 ..
drwxr-xr-x 2 root root 4096 Oct 30 05:26 lib

Comment 7 Endi Sukma Dewata 2019-11-06 20:19:22 UTC
Thanks for the info. So far everything seems normal, so I'm not sure
what's causing the problem, and I don't have the environment to reproduce
the problem. So for now the workaround is to disable the security manager
as described in comment #2.

Comment 8 Dinesh Prasanth 2019-11-07 20:52:06 UTC
This is interesting. I was able to reproduce this issue. After following comment #2,
I was able to get the proper UI.

Then, I reset the SECURITY_MANAGER="true" in both the files and restarted my server.
Interestingly, the UI works as expected.

Comment 9 Arno Lehmann 2019-12-27 16:08:50 UTC
Ok, it took me a while to notice that repsonses by mail were not added here... sorry for that.

However, I can confirm that disabling the SECURITY_MANAGER fixed the issue.

The upgrade logs show no failures, and no scriptlets run.

The directory listings look kind of boring:
[root@ca2 ~]# LANG=C ls -la /var/lib/pki/CA2/ ; LANG=C ls -la /var/lib/pki/CA2/common/
total 0
drwxrwx---. 7 pkiuser pkiuser 151 Sep  5 22:51 .
drwxr-xr-x. 3 root    root     17 Aug 15 03:04 ..
lrwxrwxrwx. 1 root    root     16 May  9  2017 CA2 -> /usr/sbin/tomcat
lrwxrwxrwx. 1 pkiuser pkiuser  18 May  9  2017 alias -> /etc/pki/CA2/alias
lrwxrwxrwx. 1 pkiuser pkiuser  21 May  9  2017 bin -> /usr/share/tomcat/bin
drwxrwx---. 5 pkiuser pkiuser 104 May  9  2017 ca
lrwxrwxrwx. 1 pkiuser pkiuser  28 May  9  2017 common -> /usr/share/pki/server/common
lrwxrwxrwx. 1 pkiuser pkiuser  12 May  9  2017 conf -> /etc/pki/CA2
lrwxrwxrwx. 1 pkiuser pkiuser  25 Sep  5 22:51 lib -> /usr/share/pki/server/lib
lrwxrwxrwx. 1 pkiuser pkiuser  16 May  9  2017 logs -> /var/log/pki/CA2
drwxrwx---. 3 pkiuser pkiuser  74 May  9  2017 ocsp
drwxrwx---. 2 pkiuser pkiuser   6 May  9  2017 temp
drwxr-xr-x. 2 pkiuser pkiuser   6 May  9  2017 webapps
drwxrwx---. 3 pkiuser pkiuser  22 May  9  2017 work
total 4
drwxr-xr-x. 3 root root   17 Aug 15 03:04 .
drwxr-xr-x. 9 root root   96 Aug 15 03:04 ..
drwxr-xr-x. 2 root root 4096 Sep 23 10:19 lib
[root@ca2 ~]# 


Thanks for the advice leading to a solution!

Arno

Comment 10 Fraser Tweedale 2020-04-21 02:24:22 UTC
I recently hit this.  Dinesh, the reason re-enabling security manager works after disabling it
is that the .class files are cached under /var/lib/pki/pki-tomcat/work/.  If you remove the
.class files, you hit the same problem.

It is a very strange issue.  Possibly related to https://bugzilla.redhat.com/show_bug.cgi?id=1347774.
I can't find any occurrence of dubious varargs use in the intermediate .java files produced by
Jasper, though.

Comment 11 Alex Scheel 2020-04-21 21:46:30 UTC
Thanks Fraser! :-)


Another workaround is to edit /usr/share/pki/server/conf/pki.policy and add the missing policy line:

https://github.com/dogtagpki/pki/pull/381/files


Coty, I think Tomcat needs an update as well. Dinesh found the following that might've not made it upstream:

https://src.fedoraproject.org/rpms/tomcat/blob/master/f/tomcat-9.0-catalina-policy.patch#_24



I think it needs to be updated with the new ecj path as well. Most of the other paths seem fine.

Comment 12 Coty Sutherland 2020-04-22 19:22:19 UTC
Thanks for pointing this out! For some reason that patch hasn't even been used (I got tired of trying to find when it was last included in the specfile).

I will update the new ECJ location and apply the patch to the policy (even though it seems nobody is using the security manager configuration) :)

Comment 13 Coty Sutherland 2020-06-08 12:39:33 UTC
Btw, I updated the policy patch (https://src.fedoraproject.org/rpms/tomcat/c/8d1457151e21f1788f277ec8ed15c83dfd44e197?branch=master) a couple months ago and the fix has been in stable for a bit with no new complaints, so I assume it's fine.

Comment 14 Ben Cotton 2020-11-03 15:36:07 UTC
This message is a reminder that Fedora 31 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 31 on 2020-11-24.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '31'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 31 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 15 Ben Cotton 2020-11-24 20:00:10 UTC
Fedora 31 changed to end-of-life (EOL) status on 2020-11-24. Fedora 31 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.