#3198 Freeipa nIghtly test failure during KRA installation
Closed: fixed 3 years ago by cipherboy. Opened 3 years ago by frenaud.

Several FreeIPA nightly tests failed during the KRA installation. See the PR [testing_master_pki] #326, with logs for:
- test_installation_TestInstallMaster
- test_installation_TestInstallWithCA_DNS2
- test_replication_layouts_TestCompleteTopologyWithCAKRA
- test_vault

The pki-kra-spawn logs show:

2020-08-02 20:32:25 WARNING: Directory already exists: /etc/pki/pki-tomcat
2020-08-02 20:32:25 WARNING: Directory already exists: /var/lib/ipa/tmp-rg_mardd
2020-08-02 20:34:16 ERROR: ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))
  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 575, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 978, in spawn
    client.finalizeConfiguration(finalize_config_request)
  File "/usr/lib/python3.8/site-packages/pki/system.py", line 511, in finalizeConfiguration
    self.connection.post(
  File "/usr/lib/python3.8/site-packages/pki/client.py", line 55, in wrapper
    return func(self, *args, **kwargs)
  File "/usr/lib/python3.8/site-packages/pki/client.py", line 293, in post
    r = self.session.post(
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 581, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)

and the journal:

Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test server[32834]: # A fatal error has been detected by the Java Runtime Environment:
Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test server[32834]: #  SIGSEGV (0xb) at pc=0x00007f361677a369, pid=32834, tid=0x00007f3617798700
Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test server[32834]: # JRE version: OpenJDK Runtime Environment (8.0_262-b10) (build 1.8.0_262-b10)
Aug 02 20:34:15 master.ipa.test server[32834]: # Java VM: OpenJDK 64-Bit Server VM (25.262-b10 mixed mode linux-amd64 compressed oops)
Aug 02 20:34:15 master.ipa.test server[32834]: # Problematic frame:
Aug 02 20:34:15 master.ipa.test server[32834]: # C  [libjss4.so+0x2c369]  Java_org_mozilla_jss_ssl_SSLSocket_shutdownNative+0x89
Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test server[32834]: # Core dump written. Default location: /usr/share/tomcat/core or core.32834
Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test server[32834]: # An error report file with more information is saved as:
Aug 02 20:34:15 master.ipa.test server[32834]: # /tmp/hs_err_pid32834.log
Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test server[32834]: # If you would like to submit a bug report, please visit:
Aug 02 20:34:15 master.ipa.test server[32834]: #   https://bugzilla.redhat.com/enter_bug.cgi?product=Fedora&component=java-1.8.0-openjdk&version=32
Aug 02 20:34:15 master.ipa.test server[32834]: # The crash happened outside the Java Virtual Machine in native code.
Aug 02 20:34:15 master.ipa.test server[32834]: # See problematic frame for where to report the bug.
Aug 02 20:34:15 master.ipa.test server[32834]: #
Aug 02 20:34:15 master.ipa.test audit[32834]: ANOM_ABEND auid=4294967295 uid=17 gid=17 ses=4294967295 subj=system_u:system_r:tomcat_t:s0 pid=32834 comm="Finalizer" exe="/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.262.b10-1.fc32.x86_64/jre/bin/java" sig=6 res=1
Aug 02 20:34:15 master.ipa.test systemd[1]: Created slice system-systemd\x2dcoredump.slice.
Aug 02 20:34:15 master.ipa.test audit: BPF prog-id=594 op=LOAD
Aug 02 20:34:15 master.ipa.test audit: BPF prog-id=595 op=LOAD
Aug 02 20:34:15 master.ipa.test audit: BPF prog-id=596 op=LOAD
Aug 02 20:34:15 master.ipa.test systemd[1]: Started Process Core Dump (PID 33069/UID 0).
Aug 02 20:34:15 master.ipa.test audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-coredump@0-33069-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Aug 02 20:34:16 master.ipa.test systemd[1]: pki-tomcatd@pki-tomcat.service: Main process exited, code=killed, status=6/ABRT
Aug 02 20:34:16 master.ipa.test systemd[1]: pki-tomcatd@pki-tomcat.service: Failed with result 'signal'.
Aug 02 20:34:16 master.ipa.test audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=pki-tomcatd@pki-tomcat comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Aug 02 20:34:16 master.ipa.test systemd[1]: pki-tomcatd@pki-tomcat.service: Consumed 38.978s CPU time.
Aug 02 20:34:17 master.ipa.test audit[27882]: USER_END pid=27882 uid=0 auid=0 ses=6 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login id=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.122.242 terminal=ssh res=success'
Aug 02 20:34:18 master.ipa.test audit[27882]: USER_START pid=27882 uid=0 auid=0 ses=6 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login id=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.122.242 terminal=ssh res=success'
Aug 02 20:34:18 master.ipa.test audit[27882]: CRYPTO_KEY_USER pid=27882 uid=0 auid=0 ses=6 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=SHA256:92:cd:18:a4:cf:8b:45:2c:d5:5a:1f:d5:a8:e3:70:c5:2b:f1:f1:ca:b2:20:0d:0b:f8:b1:9b:b7:0a:ab:e2:4e direction=? spid=33072 suid=0  exe="/usr/sbin/sshd" hostname=? addr=? terminal=? res=success'
Aug 02 20:34:18 master.ipa.test systemd-coredump[33070]: Process 32834 (java) of user 17 dumped core.

                                                         Stack trace of thread 32848:
                                                         #0  0x00007f362d7aa9e5 raise (libc.so.6 + 0x3c9e5)
                                                         #1  0x00007f362d793895 abort (libc.so.6 + 0x25895)
                                                         #2  0x00007f362ca8f4d1 _ZN2os5abortEb.cold (libjvm.so + 0x2114d1)
                                                         #3  0x00007f362d439a32 _ZN7VMError14report_and_dieEv (libjvm.so + 0xbbba32)
                                                         #4  0x00007f362d22d934 JVM_handle_linux_signal (libjvm.so + 0x9af934)
                                                         #5  0x00007f362d2209ac _Z13signalHandleriP9siginfo_tPv (libjvm.so + 0x9a29ac)
                                                         #6  0x00007f362d7aaa70 __restore_rt (libc.so.6 + 0x3ca70)
                                                         #7  0x00007f361677a369 Java_org_mozilla_jss_ssl_SSLSocket_shutdownNative (libjss4.so + 0x2c369)
                                                         #8  0x00007f36187443c7 n/a (n/a + 0x0)
                                                         #9  0x00007f3618733ffd n/a (n/a + 0x0)
                                                         #10 0x00007f3618733ffd n/a (n/a + 0x0)
                                                         #11 0x00007f3618733ffd n/a (n/a + 0x0)
                                                         #12 0x00007f3618734042 n/a (n/a + 0x0)
                                                         #13 0x00007f3618733ffd n/a (n/a + 0x0)
                                                         #14 0x00007f3618733ffd n/a (n/a + 0x0)
                                                         #15 0x00007f36189575d8 n/a (n/a + 0x0)

Installed packages versions can be found here:
- 389-ds-base-1.4.3.11-1.fc32.x86_64
- pki-base-10.9.0-1.20200801025303UTC.b047c132.fc32.noarch
- nss-3.54.0-1.fc32.x86_64
- java-1.8.0-openjdk-headless-1.8.0.262.b10-1.fc32.x86_64
- jss-4.7.0-1.20200728193830UTC.f4a874f9.fc32.x86_64
- tomcatjss-7.5.0-1.20200731010237UTC.7ac6223e.fc32.noarch
- tomcat-9.0.36-1.fc32.noarch


Interesting. Note that this isn't with the new JSS SSLEngine, but with the old SSLSocket.

This largely should happen as the socket should really only be closed once. Notably, we have changed something related recently:

https://github.com/dogtagpki/pki/pull/501

However, the new code doesn't call shutdown, so I'm confused how a NULL pointer dereference could happen.

I've added some more guards to JSS that I'll open as a PR.

Metadata Update from @cipherboy:
- Custom field component adjusted to None
- Custom field feature adjusted to None
- Custom field origin adjusted to None
- Custom field proposedmilestone adjusted to None
- Custom field proposedpriority adjusted to None
- Custom field reviewer adjusted to None
- Custom field type adjusted to None
- Custom field version adjusted to None

3 years ago

Metadata Update from @cipherboy:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)

3 years ago

Dogtag PKI is moving from Pagure issues to GitHub issues. This means that existing or new
issues will be reported and tracked through Dogtag PKI's GitHub Issue tracker.

This issue has been cloned to GitHub and is available here:
https://github.com/dogtagpki/pki/issues/3315

If you want to receive further updates on the issue, please navigate to the
GitHub issue and click on Subscribe button.

Thank you for understanding, and we apologize for any inconvenience.

Login to comment on this ticket.

Metadata