I did some further investigation. with strace
SEGSEGV was raised 0.000044 after start up:
0.000044 --- SIGSEGV {si_signo=SIGSEGV, si_code=SI_USER, si_pid=52811, si_uid=0} ---
0.116226 +++ killed by SIGSEGV (core dumped) +++
OS:  4.18.0-348.20.1.el8_5.x86_64

on a reference machine with  4.18.0-348.7.1.el8_5.x86_64 it works, even if there are workers, which could not be resolved.

You have no provided enough information to investigate this crash.

Does the log file end after what you have posted?

Please post the full backtrace of the crash, or, if you are comfortable doing so, the core file from the crash.

Created attachment 38247 [details]
debug logs related to server level

Created attachment 38248 [details]
debug log related to vHost

Hi Christopher,
yes, these where the last log entries.
I attached the full debug logs.
Sorry, but I can`t upload the core file.
This behavior is since last patching of RHEL8.
But right now, I don`t know, which of the 120 updated packages causes the Issue

status changed from needinfo to new

Please post a native backtrace from the core dump.

is it this, what you need:
coredumpctl -o dump_LBE dump 15030
           PID: 15030 (httpd)
           UID: 0 (root)
           GID: 0 (root)
        Signal: 11 (SEGV)
     Timestamp: Thu 2022-04-14 16:03:59 CEST (1min 11s ago)
  Command Line: /opt/apache24/bin/httpd -f /opt/apache24/conf/httpd.conf-Q9Z -DSSLONLB -DJK -DJKLB -DTEST
    Executable: /opt/apache24-2.4.53/bin/httpd
 Control Group: /system.slice/sshd.service
          Unit: sshd.service
         Slice: system.slice
       Boot ID: ac861fcf54ce466d85c01858284f6002
    Machine ID: 75f51ab102f24402a778885cc10db4ea
      Hostname: usq9ztlws002.internal.unicreditgroup.eu
       Storage: /var/lib/systemd/coredump/core.httpd.0.ac861fcf54ce466d85c01858284f6002.15030.1649945039000000.lz4
       Message: Process 15030 (httpd) of user 0 dumped core.

                Stack trace of thread 15030:
                #0  0x00007ff793710dbf run_cleanups (libapr-1.so.0)
                #1  0x00007ff79370fae5 apr_pool_clear (libapr-1.so.0)
                #2  0x00007ff78f397534 jk_resolve (mod_jk.so)
                #3  0x00007ff78f3c32bc ajp_validate (mod_jk.so)
                #4  0x00007ff78f3a2f4a validate (mod_jk.so)
                #5  0x00007ff78f3a1eb5 wc_create_worker (mod_jk.so)
                #6  0x00007ff78f3a9970 validate (mod_jk.so)
                #7  0x00007ff78f3a1eb5 wc_create_worker (mod_jk.so)
                #8  0x00007ff78f3a25bf build_worker_map (mod_jk.so)
                #9  0x00007ff78f3a174b wc_open (mod_jk.so)
                #10 0x00007ff78f392d2a init_jk (mod_jk.so)
                #11 0x00007ff78f393602 jk_post_config (mod_jk.so)
                #12 0x0000000000465c2c ap_run_post_config (httpd)
                #13 0x0000000000431b9f main (httpd)
                #14 0x00007ff792af1493 __libc_start_main (libc.so.6)
                #15 0x000000000042fe3e _start (httpd)

Created attachment 38250 [details]
Dumpfile

I replaced sensitive data, hoepfully completely and without damaging the dump

Are you able to build a patched version of mod_jk? I'd like to add some logging to figure out what's happening.

It looks like we are trying to "clean" an APR memory pool and something is wrong with the pool.

It seems the crash happens in the second parent during the Apache startup. On Unix/Linux Apache creates a first parent, then replaces it by another parent and then starts the children. The first parent validates both workers without crash. Then the pid changes and the second parent starts, which crashes.

The pool "jk_apr_pool" in common/jk_connect.c is static and only initialized, if it is NULL. I think we use the Apache pconf pool as the parent pool. I added debug logging lines and both parents seem to ahve the same address for pconf and both parents create a new fresh jk_apr_pool in my system. So I see no reason for a crash and indeed on my system it doesn't crash.

Some questions:

Am I right this happens immediately during the web server startup attempt?
Are you starting with requests immediately hitting the web server?
If so, can you retry with the web server not receiving any requests during startup?
What MPM are you using?
What exact Apache version?
What exact APR version?
Apache and/or APR self-compiled or Linux Distro provided.
Linux Distro RHEL 8?

Since this seems to happen early during startup, could you strip down your config to not use any other 3rd-party modules (like mod_security, PHP etc.) just to do another crash check?

A simple patch that adds a few log lines that help us verify, that the pool lifecycle on your system doesn't differ from mine:

diff -u common/jk_connect.c.kpdt_orig common/jk_connect.c
--- common/jk_connect.c.kpdt_orig       2022-04-15 00:34:15.139451326 +0200
+++ common/jk_connect.c 2022-04-15 00:32:54.311258693 +0200
@@ -416,10 +416,15 @@
         apr_sockaddr_t *remote_sa, *temp_sa;

         if (!jk_apr_pool) {
+            jk_log(l, JK_LOG_ERROR, "Creating jk_apr_pool from main pool %pp", pool);
             if (apr_pool_create(&jk_apr_pool, (apr_pool_t *)pool) != APR_SUCCESS) {
+                jk_log(l, JK_LOG_ERROR, "Failed creating jk_apr_pool from main pool %pp", pool);
                 JK_TRACE_EXIT(l);
                 return JK_FALSE;
             }
+            jk_log(l, JK_LOG_ERROR, "Created jk_apr_pool %pp from main pool %pp", jk_apr_pool, pool);
+        } else {
+            jk_log(l, JK_LOG_ERROR, "Reusing jk_apr_pool %pp, main pool %pp", jk_apr_pool, pool);
         }
         apr_pool_clear(jk_apr_pool);
         if (apr_sockaddr_info_get(&remote_sa, host, APR_UNSPEC, (apr_port_t)port,

This will add log lines like:

[Fri Apr 15 00:43:19.335 2022] [10189:140241031051136] [error] jk_resolve::jk_connect.c (419): Creating jk_apr_pool from main pool 0x797478p
[Fri Apr 15 00:43:19.335 2022] [10189:140241031051136] [error] jk_resolve::jk_connect.c (425): Created jk_apr_pool 0x81bfd8p from main pool 0x797478p
[Fri Apr 15 00:43:19.343 2022] [10189:140241031051136] [error] ajp_validate::jk_ajp_common.c (2868): worker node1 can't resolve tomcat address unknown.example.com

[Fri Apr 15 00:43:19.344 2022] [10189:140241031051136] [error] jk_resolve::jk_connect.c (427): Reusing jk_apr_pool 0x81bfd8p, main pool 0x797478p
[Fri Apr 15 00:43:19.344 2022] [10189:140241031051136] [error] ajp_validate::jk_ajp_common.c (2868): worker node2 can't resolve tomcat address unknown.example.com

[Fri Apr 15 00:43:19.359 2022] [10192:140241031051136] [error] jk_resolve::jk_connect.c (419): Creating jk_apr_pool from main pool 0x797478p
[Fri Apr 15 00:43:19.359 2022] [10192:140241031051136] [error] jk_resolve::jk_connect.c (425): Created jk_apr_pool 0x7c8788p from main pool 0x797478p
[Fri Apr 15 00:43:19.359 2022] [10192:140241031051136] [error] ajp_validate::jk_ajp_common.c (2868): worker node1 can't resolve tomcat address unknown.example.com

[Fri Apr 15 00:43:19.360 2022] [10192:140241031051136] [error] jk_resolve::jk_connect.c (427): Reusing jk_apr_pool 0x7c8788p, main pool 0x797478p
[Fri Apr 15 00:43:19.360 2022] [10192:140241031051136] [error] ajp_validate::jk_ajp_common.c (2868): worker node2 can't resolve tomcat address unknown.example.com

Thanks and regards,

Rainer

Hi Rainer,
Yes, this happens immediately after start up.
According to strace 47µs after start:
     0.000047 rt_sigreturn({mask=[]})   = 3342918277296713689
     0.000047 --- SIGSEGV {si_signo=SIGSEGV, si_code=SI_USER, si_pid=3657936, si_uid=0} ---
     0.143521 +++ killed by SIGSEGV (core dumped) +++
I tried both MPM prefork and worker. (but usually we use prefork)
Apache 2.4.53 ( I tried also older Versions like 2.4.46)
APR: 1.7.0 / APR-Util 1.6.1
We are using self compiled binaries.
Yes it is RHEL8 4.18.0-348.20.1.el8_5.x86_64
The self compiled binaries we are using since more then 10 years
But after last OS patching we have such issue, I never experienced something like this. Yes, I think there is something in conflict between OS and our apache modules/libraries.

No there are no incomming requests it is a development environment.

This is the output, after adding your log enhancements:
[Fri Apr 15 12:32:15.822 2022] [482404:0] [error] jk_resolve::jk_connect.c (419): Creating jk_apr_pool from main pool 0x25783c8p
[Fri Apr 15 12:32:15.822 2022] [482404:0] [error] jk_resolve::jk_connect.c (425): Created jk_apr_pool 0x2625098p from main pool 0x25783c8p
[Fri Apr 15 12:32:15.959 2022] [482404:0] [error] ajp_validate::jk_ajp_common.c (2868): worker theWorker1 can't resolve tomcat address host2.example.org
[Fri Apr 15 12:32:15.959 2022] [482404:0] [error] jk_resolve::jk_connect.c (427): Reusing jk_apr_pool 0x2625098p, main pool 0x25783c8p
[Fri Apr 15 12:32:16.067 2022] [482404:0] [error] ajp_validate::jk_ajp_common.c (2868): worker theWorker0 can't resolve tomcat address host1.example.org
[Fri Apr 15 12:32:16.067 2022] [482404:0] [info] init_jk::mod_jk.c (3591): mod_jk/1.2.48 initialized
[Fri Apr 15 12:32:16.075 2022] [482433:0] [error] jk_resolve::jk_connect.c (427): Reusing jk_apr_pool 0x2625098p, main pool 0x25783c8p

Thanks a lot for your support. KR, Lothar

(In reply to Lothar from comment #12)
> I tried both MPM prefork and worker. (but usually we use prefork)
> Apache 2.4.53 ( I tried also older Versions like 2.4.46)
> APR: 1.7.0 / APR-Util 1.6.1
> We are using self compiled binaries.
> Yes it is RHEL8 4.18.0-348.20.1.el8_5.x86_64
> The self compiled binaries we are using since more then 10 years
> But after last OS patching we have such issue, I never experienced something
> like this. Yes, I think there is something in conflict between OS and our
> apache modules/libraries.

This is what I would expect. The code which is crashing (when calling apr_pool_clear) was added in 2009, so something has been introduced lately which is causing some problem.

Can you be sure that the version of APR you are using for the build is the same version being used at runtime?

In strace I found the following file openings related to apr:
3657933:     0.000051 openat(AT_FDCWD, "/opt/apache24/lib/libaprutil-1.so.0", O_RDONLY|O_CLOEXEC) = 3
3657933:     0.000059 openat(AT_FDCWD, "/opt/apache24/lib/libapr-1.so.0", O_RDONLY|O_CLOEXEC) = 3
So the lib is the same as we provide with our package and the same Version.

By the way, you asked about php, mod_security, they are not loaded.

Is it possible to enable a similar logging in apr?
How to implement?

Meanwhile I found the cause:
systemd-239-51.el8_5.5.x86_64 is updating /etc/nsswitch.conf
< hosts:      files dns
---
> hosts:      files dns myhostname

after removing myhostname it works again.
see: https://access.redhat.com/solutions/1287253
So probably after each patching cycle of systemd, we have to check "/etc/nsswitch.conf".
Hopefully there would be finally a better solution.
Anyway, thanks, for your support.
KR, Lothar

That's really very strange. "myhostname" is something RHEL-specific which I am unable to test, but whatever it is should not cause mod_jk or httpd to crash.

Rainer, do you have any explanation for what this could be? mod_jk is just trying to clean-up its own resources and the code looks good. Is it possible that our pointed has been trashed by some other code?

Unfortunately I have no explanation:

- my RHEL 8 test system did also have the myhostname entry without problem

- his debug log output showed different behavior than mine with respect to pool reuse, but I do not know how that would explain the crash

But since the name resolution only happens at worker init time, one could think about not reusing the memory pool at all, so not having it as a static member.

Regards,

Rainer

I have two customers reporting the same issue on SLES15-SP4 but I can't reproduce it by myself.

With additional debug messages like in comment #11 log showed that it crashed when jk_resolve() was reusing jk_apr_pool with address that was correctly initialized in previous jk_resolve call. However in time of reuse the memory pointed to by jk_apr_pool contained "random" data and also "pconf" pool passed to jk_resolve() as "pool" argument had not jk_apr_pool in it's list of children.

When I tried to reproduce the pool was never reused because it was called only once during module initialization and every apache ap_config_generation generation caused module was unload/load and it reset the jk_apr_pool variable back to NULL.

To fix it I created a patch that creates new pool on every jk_resolve() call as suggested in comment #18. With this customers reported that the issue is fixed.

Created attachment 38503 [details]
Do not reuse jk_apr_pool

Created attachment 38538 [details]
Limit mod_jk.so exported symbols to "jk_module" only.

I found the real culprit. Please ignore my previous patch.

ATM mod_jk.so library exports all internal symbols so any other library loaded after it can bind it's unresolved symbols on mod_jk.so. Glibc is checking dependencies and dlclose() does not unload library on which depends other library. This breaks Apache module reloading mechanism because following dlopen() will return already existing handler to mod_jk.so without re-initialization of global static variables so they contain still already invalid memory pointers instead of NULL values.

In my case symbol "context_free@@LIBSELINUX_1.0" required by libkrb5support.so was bound to context_free from mod_jk.so instead of function with the same name provided by libselinux.so.1 because mod_jk.so was loaded first. It occurred only if nscd daemon was disabled and nsswitch had to load krb5 libraries. I can easily reproduce the issue on SLES15-SP4 by disabling nscd service. IMO this can also explain why Lothar reported that his issue disappeared after modifying nsswitch.conf.

Thanks for the great finding!

I plan to apply your patch.

Since -E is not a standardized linker flag I would rather prefer to not include it. For me it made no difference, whether I add the -Wl,-E (so the -E flag for ld). the full "nm" output was the same when uusing it and when not using it, alsways combined with out symbol regexp.

Thanks and regards,

Rainer

Too many typos:

Thanks for the great finding!

I plan to apply your patch.

Since -E is not a standardized linker flag I would rather prefer to not include it. For me it made no difference, whether I add the -Wl,-E (so the -E flag for ld). the full "nm" output was the same when using it and when not using it, always combined with your symbol regexp.

Thanks and regards,

Rainer

The patch provided is highly not portable. Why not use internal attributes which mark symbols as public/private?

Not sure how highly nonportable, at least it uses libtool.

Attributes are often used in GCC style. Do you have a concrete suggestion how to use them in a portable way to only export the jk_handler symbol?

(In reply to Rainer Jung from comment #25)
> Not sure how highly nonportable, at least it uses libtool.
> 
> Attributes are often used in GCC style. Do you have a concrete suggestion
> how to use them in a portable way to only export the jk_handler symbol?

Others supply a file of per-line symbols which should be visible externally. That can be made portable because all linkers support it.

(In reply to Josef Čejka from comment #21)
> Created attachment 38538 [details]
> Limit mod_jk.so exported symbols to "jk_module" only.
> 
> I found the real culprit. Please ignore my previous patch.
> 
> ATM mod_jk.so library exports all internal symbols so any other library
> loaded after it can bind it's unresolved symbols on mod_jk.so. Glibc is
> checking dependencies and dlclose() does not unload library on which depends
> other library. This breaks Apache module reloading mechanism because
> following dlopen() will return already existing handler to mod_jk.so without
> re-initialization of global static variables so they contain still already
> invalid memory pointers instead of NULL values.
> 
> In my case symbol "context_free@@LIBSELINUX_1.0" required by
> libkrb5support.so was bound to context_free from mod_jk.so instead of
> function with the same name provided by libselinux.so.1 because mod_jk.so
> was loaded first. It occurred only if nscd daemon was disabled and nsswitch
> had to load krb5 libraries. I can easily reproduce the issue on SLES15-SP4
> by disabling nscd service. IMO this can also explain why Lothar reported
> that his issue disappeared after modifying nsswitch.conf.

Josef,

kudos to your investigation skills!

Rainer, do you have a timescale in mind for applying the proposed patch or a variation? I'm planning on a mod_jk tag and release soon - hopefully this week.

I don't have a solution ready in the direction that Michael mentions. Because we don't call a linker directly and we don't want to. Linker flags are not standardized. That's one reason for using libtool.

So I would apply the libtool "solution" in the next minutes and if we find a better solution before the tag we can optimize. For me the original libtool solution works in a release.

Sounds good to me. Tx.

I checked the libtool code. It provides the option -export-symbols-regexp, which was suggested and which I know committed, and it also provides -export-symbols with a file name containing the symbols. The implementation in libtool is very similar. It first generates a full symbol list, then filters the list (using egrep -e, or egrep) then then calls the linker with the result. So the portability of both ways is pretty much the same and expected to be good when using libtool. In our case having a separate symbol file doesn't seem to be necessary, because the contract between the module and the httpd web server is just this one stable symbol name.

Committed in GH eda74b19e4800e3ed8bb3351d8995d1b3eb44a4d.

Will be part of 1.2.49.

(In reply to Rainer Jung from comment #31)
> I checked the libtool code. It provides the option -export-symbols-regexp,
> which was suggested and which I know committed, and it also provides
> -export-symbols with a file name containing the symbols. The implementation
> in libtool is very similar. It first generates a full symbol list, then
> filters the list (using egrep -e, or egrep) then then calls the linker with
> the result. So the portability of both ways is pretty much the same and
> expected to be good when using libtool. In our case having a separate symbol
> file doesn't seem to be necessary, because the contract between the module
> and the httpd web server is just this one stable symbol name.
> 
> Committed in GH eda74b19e4800e3ed8bb3351d8995d1b3eb44a4d.
> 
> Will be part of 1.2.49.

Then, I am happy with this since libtool will properly abstract from the actual linker calls. Thank for the investigation!

Unfortunately apache-2.0/Makefile.in contains a type, the flag was named -export-symbols-regexp instead of -export-symbols-regex (no "p" at the end of the flag name). To make this fix work, one has to fix this typo in that Makefile.in before building mod_jk (or wait for version 1.2.50).