So, I'm still feeling this bug out. But, in the last couple of days, several FreeIPA-related tests have failed in openQA in similar ways. https://openqa.fedoraproject.org/tests/477587 is one example. https://openqa.fedoraproject.org/tests/476911 is another. https://openqa.fedoraproject.org/tests/476877 is another. In all those cases, we get an error during FreeIPA server deployment when we try to connect to dogtag running on port 8443. In all those cases, looking at the journal (you can find a tarball of /var/log on the "Logs & Assets" tab for each test), we see a java.Lang.NullPointerException. One doesn't provide a traceback for some reason, but the other two provide one like this: Oct 26 12:31:42 ipa001.domain.local server[6457]: SEVERE: Error running socket processor Oct 26 12:31:42 ipa001.domain.local server[6457]: java.lang.Error: Error during hash calculation Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.HandshakeHash.getFinishedHash(HandshakeHash.java:272) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.HandshakeMessage$Finished.getFinished(HandshakeMessage.java:1951) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.HandshakeMessage$Finished.verify(HandshakeMessage.java:1920) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.ServerHandshaker.clientFinished(ServerHandshaker.java:1788) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.ServerHandshaker.processMessage(ServerHandshaker.java:317) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1037) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.Handshaker.process_record(Handshaker.java:965) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:1015) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:896) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:766) Oct 26 12:31:42 ipa001.domain.local server[6457]: at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.apache.tomcat.util.net.SecureNioChannel.handshakeUnwrap(SecureNioChannel.java:499) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.apache.tomcat.util.net.SecureNioChannel.handshake(SecureNioChannel.java:238) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1566) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.lang.Thread.run(Thread.java:748) Oct 26 12:31:42 ipa001.domain.local server[6457]: Caused by: java.lang.NullPointerException Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.util.NativeProxy.equals(NativeProxy.java:64) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.util.HashMap.putVal(HashMap.java:635) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.util.HashMap.put(HashMap.java:612) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.util.HashSet.add(HashSet.java:220) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.util.NativeProxy.<init>(NativeProxy.java:43) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.pkcs11.CipherContextProxy.<init>(CipherContextProxy.java:11) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.pkcs11.PK11MessageDigest.initDigest(Native Method) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.pkcs11.PK11MessageDigest.reset(PK11MessageDigest.java:96) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.pkcs11.PK11MessageDigest.digest(PK11MessageDigest.java:87) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.crypto.JSSMessageDigest.digest(JSSMessageDigest.java:65) Oct 26 12:31:42 ipa001.domain.local server[6457]: at org.mozilla.jss.provider.java.security.JSSMessageDigestSpi.engineDigest(JSSMessageDigestSpi.java:56) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.security.MessageDigest$Delegate.engineDigest(MessageDigest.java:592) Oct 26 12:31:42 ipa001.domain.local server[6457]: at java.security.MessageDigest.digest(MessageDigest.java:365) Oct 26 12:31:42 ipa001.domain.local server[6457]: at sun.security.ssl.HandshakeHash.getFinishedHash(HandshakeHash.java:270) Oct 26 12:31:42 ipa001.domain.local server[6457]: ... 18 more I also note that a JSS update recently went stable across F29, F30 and F31: https://bodhi.fedoraproject.org/updates/FEDORA-2019-4d33c62860 (F29) https://bodhi.fedoraproject.org/updates/FEDORA-2019-68c2fbcf82 (F30) https://bodhi.fedoraproject.org/updates/FEDORA-2019-24a0a2f24e (F31) at the point it went stable it would start being used in these openQA tests, and that's approximately when these errors started showing up. So between that and the backtrace...jss 4.6.2 is my suspect for now. This bug doesn't seem to happen on *every* attempt; on some updates the tests are passing, and when I re-ran all the failures I saw today, most of them passed at the second attempt. The tests being run here are deploying a FreeIPA server in a pretty standard way, please ask if more details are needed.
Created attachment 1629987 [details] /var/log tarball from one of the failures
Assigned; patch here -- will get it into a Fedora update for people to test today. https://github.com/dogtagpki/jss/pull/299
Built in Rawhide: https://koji.fedoraproject.org/koji/taskinfo?taskID=38646690 Adam did a scratch build for F31 and is running tests here: https://openqa.stg.fedoraproject.org/tests/overview?distri=fedora&version=31&build=Kojitask-38647088-NOREPORT&groupid=2 Once that is done and I get the thumbs up, I'll backport to F31...F29. Thanks!
I ran through the FreeIPA tests four times and they all passed, so that looks good. Please send out updates for F29..F31. Thanks! Note, POST for Fedora bugs means "fix is available upstream (as a PR or a commit) but has not yet reached an official Fedora package", i.e. it's the appropriate status for this bug.
FEDORA-2019-2613ca7581 has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2019-2613ca7581
FEDORA-2019-4129cdf50b has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-4129cdf50b
FEDORA-2019-7685c49b92 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2019-7685c49b92
jss-4.6.2-2.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.
I had two IPA servers that are in pairs. After installing the jss from updates-testing channel. One of them complete the ipa-server-upgrade process but the tomcat/pki/ca is not function. Another server cannot complete the ipa-server-upgrade process. I had capture some logs and posted in the forum: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org/thread/4HJSWIJQQYZQXUCEDUNZGPEKMOE7Z3MD/ Thanks.
For #9, I am using FC31.
jss-4.6.2-2.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.
jss-4.6.2-2.fc31 has been pushed to the Fedora 31 stable repository. If problems still persist, please make note of it in this bug report.
This message is a reminder that Fedora 30 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora 30 on 2020-05-26. 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 '30'. 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 30 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.