Enabling Metrics Endpoint causes Segmentation Faults during Shutdown

[studersi]

When enabling the new Prometheus metrics endpoint, we see memory corruption errors. Sometimes this causes backtraces to be logged:

OIDCMetricsData                     authtype authn authz require.claim session cache redirect_uri content
OIDCMetricsPublish                  /path/to/endpoint

Sometimes we see this in the logs:

double free or corruption (!prev)

Sometimes we see more information:

*** Error in `/opt/apache24/bin/httpd': double free or corruption (!prev): 0x000055b73b3503b0 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x81329)[0x7f52fe5e3329]
/opt/apache24/lib/libapr-1.so.0(apr_allocator_destroy+0x1d)[0x7f52ff3b534d]
/opt/apache24/lib/libapr-1.so.0(apr_pool_terminate+0x30)[0x7f52ff3b5d20]
/opt/apache24/bin/httpd(+0x39590)[0x55b739fb7590]
/opt/apache24/bin/httpd(main+0xb94)[0x55b739fb7284]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f52fe584555]
/opt/apache24/bin/httpd(+0x393cd)[0x55b739fb73cd]
======= Memory map: ========
55b739f7e000-55b73a01d000 r-xp 00000000 fd:03 27770                      /opt/apache24/bin/httpd
55b73a21d000-55b73a220000 r--p 0009f000 fd:03 27770                      /opt/apache24/bin/httpd
55b73a220000-55b73a224000 rw-p 000a2000 fd:03 27770                      /opt/apache24/bin/httpd
55b73a224000-55b73a228000 rw-p 00000000 00:00 0
55b73b31f000-55b73c861000 rw-p 00000000 00:00 0                          [heap]
55b73c861000-55b73c950000 rw-p 00000000 00:00 0                          [heap]
7f52e8e21000-7f52e8e22000 ---p 00000000 00:00 0
7f52e8e22000-7f52e9622000 rw-p 00000000 00:00 0
7f52ec000000-7f52ec021000 rw-p 00000000 00:00 0
7f52ec021000-7f52f0000000 ---p 00000000 00:00 0
7f52f5fc9000-7f52f5fde000 r-xp 00000000 fd:00 4752319                    /usr/lib64/libgcc_s-4.8.5-20150702.so.1
7f52f5fde000-7f52f61dd000 ---p 00015000 fd:00 4752319                    /usr/lib64/libgcc_s-4.8.5-20150702.so.1
7f52f61dd000-7f52f61de000 r--p 00014000 fd:00 4752319                    /usr/lib64/libgcc_s-4.8.5-20150702.so.1
7f52f61de000-7f52f61df000 rw-p 00015000 fd:00 4752319                    /usr/lib64/libgcc_s-4.8.5-20150702.so.1
7f52f61df000-7f52f61eb000 r-xp 00000000 fd:00 4230555                    /usr/lib64/libnss_files-2.17.so
7f52f61eb000-7f52f63ea000 ---p 0000c000 fd:00 4230555                    /usr/lib64/libnss_files-2.17.so
7f52f63ea000-7f52f63eb000 r--p 0000b000 fd:00 4230555                    /usr/lib64/libnss_files-2.17.so
7f52f63eb000-7f52f63ec000 rw-p 0000c000 fd:00 4230555                    /usr/lib64/libnss_files-2.17.so
7f52f63ec000-7f52f63f2000 rw-p 00000000 00:00 0
7f52f907d000-7f52f950b000 r-xp 00000000 fd:03 100663933                  /opt/apache24/lib/libcrypto.so.3
7f52f950b000-7f52f970a000 ---p 0048e000 fd:03 100663933                  /opt/apache24/lib/libcrypto.so.3
7f52f970a000-7f52f9765000 r--p 0048d000 fd:03 100663933                  /opt/apache24/lib/libcrypto.so.3
7f52f9765000-7f52f9769000 rw-p 004e8000 fd:03 100663933                  /opt/apache24/lib/libcrypto.so.3
7f52f9769000-7f52f976c000 rw-p 00000000 00:00 0
7f52f976c000-7f52f9826000 r-xp 00000000 fd:03 100682765                  /opt/apache24/lib/libssl.so.3
7f52f9826000-7f52f9a25000 ---p 000ba000 fd:03 100682765                  /opt/apache24/lib/libssl.so.3
7f52f9a25000-7f52f9a2e000 r--p 000b9000 fd:03 100682765                  /opt/apache24/lib/libssl.so.3
7f52f9a2e000-7f52f9a34000 rw-p 000c2000 fd:03 100682765                  /opt/apache24/lib/libssl.so.3
7f52fe35f000-7f52fe361000 r-xp 00000000 fd:00 4195130                    /usr/lib64/libfreebl3.so
7f52fe361000-7f52fe560000 ---p 00002000 fd:00 4195130                    /usr/lib64/libfreebl3.so
7f52fe560000-7f52fe561000 r--p 00001000 fd:00 4195130                    /usr/lib64/libfreebl3.so
7f52fe561000-7f52fe562000 rw-p 00002000 fd:00 4195130                    /usr/lib64/libfreebl3.so
7f52fe562000-7f52fe726000 r-xp 00000000 fd:00 4195610                    /usr/lib64/libc-2.17.so
7f52fe726000-7f52fe925000 ---p 001c4000 fd:00 4195610                    /usr/lib64/libc-2.17.so
7f52fe925000-7f52fe929000 r--p 001c3000 fd:00 4195610                    /usr/lib64/libc-2.17.so
7f52fe929000-7f52fe92b000 rw-p 001c7000 fd:00 4195610                    /usr/lib64/libc-2.17.so
7f52fe92b000-7f52fe930000 rw-p 00000000 00:00 0
7f52fe930000-7f52fe932000 r-xp 00000000 fd:00 4195645                    /usr/lib64/libdl-2.17.so
7f52fe932000-7f52feb32000 ---p 00002000 fd:00 4195645                    /usr/lib64/libdl-2.17.so
7f52feb32000-7f52feb33000 r--p 00002000 fd:00 4195645                    /usr/lib64/libdl-2.17.so
7f52feb33000-7f52feb34000 rw-p 00003000 fd:00 4195645                    /usr/lib64/libdl-2.17.so
7f52feb34000-7f52feb4b000 r-xp 00000000 fd:00 4230563                    /usr/lib64/libpthread-2.17.so
7f52feb4b000-7f52fed4a000 ---p 00017000 fd:00 4230563                    /usr/lib64/libpthread-2.17.so
7f52fed4a000-7f52fed4b000 r--p 00016000 fd:00 4230563                    /usr/lib64/libpthread-2.17.so
7f52fed4b000-7f52fed4c000 rw-p 00017000 fd:00 4230563                    /usr/lib64/libpthread-2.17.so
7f52fed4c000-7f52fed50000 rw-p 00000000 00:00 0
7f52fed50000-7f52fed58000 r-xp 00000000 fd:00 4195642                    /usr/lib64/libcrypt-2.17.so
7f52fed58000-7f52fef57000 ---p 00008000 fd:00 4195642                    /usr/lib64/libcrypt-2.17.so
7f52fef57000-7f52fef58000 r--p 00007000 fd:00 4195642                    /usr/lib64/libcrypt-2.17.so
7f52fef58000-7f52fef59000 rw-p 00008000 fd:00 4195642                    /usr/lib64/libcrypt-2.17.so
7f52fef59000-7f52fef87000 rw-p 00000000 00:00 0
7f52fef87000-7f52fef8e000 r-xp 00000000 fd:00 4230631                    /usr/lib64/librt-2.17.so
7f52fef8e000-7f52ff18d000 ---p 00007000 fd:00 4230631                    /usr/lib64/librt-2.17.so
7f52ff18d000-7f52ff18e000 r--p 00006000 fd:00 4230631                    /usr/lib64/librt-2.17.so
7f52ff18e000-7f52ff18f000 rw-p 00007000 fd:00 4230631                    /usr/lib64/librt-2.17.so
7f52ff18f000-7f52ff193000 r-xp 00000000 fd:00 4219042                    /usr/lib64/libuuid.so.1.3.0
7f52ff193000-7f52ff392000 ---p 00004000 fd:00 4219042                    /usr/lib64/libuuid.so.1.3.0
7f52ff392000-7f52ff393000 r--p 00003000 fd:00 4219042                    /usr/lib64/libuuid.so.1.3.0
7f52ff393000-7f52ff394000 rw-p 00004000 fd:00 4219042                    /usr/lib64/libuuid.so.1.3.0
7f52ff394000-7f52ff3cd000 r-xp 00000000 fd:03 100663901                  /opt/apache24/lib/libapr-1.so.0.7.4
7f52ff3cd000-7f52ff5cd000 ---p 00039000 fd:03 100663901                  /opt/apache24/lib/libapr-1.so.0.7.4
7f52ff5cd000-7f52ff5ce000 r--p 00039000 fd:03 100663901                  /opt/apache24/lib/libapr-1.so.0.7.4
7f52ff5ce000-7f52ff5cf000 rw-p 0003a000 fd:03 100663901                  /opt/apache24/lib/libapr-1.so.0.7.4
7f52ff5cf000-7f52ff5f7000 r-xp 00000000 fd:00 4219148                    /usr/lib64/libexpat.so.1.6.0
7f52ff5f7000-7f52ff7f7000 ---p 00028000 fd:00 4219148                    /usr/lib64/libexpat.so.1.6.0
7f52ff7f7000-7f52ff7f9000 r--p 00028000 fd:00 4219148                    /usr/lib64/libexpat.so.1.6.0
7f52ff7f9000-7f52ff7fa000 rw-p 0002a000 fd:00 4219148                    /usr/lib64/libexpat.so.1.6.0
7f52ff7fa000-7f52ff825000 r-xp 00000000 fd:03 100663912                  /opt/apache24/lib/libaprutil-1.so.0.6.3
7f52ff825000-7f52ffa25000 ---p 0002b000 fd:03 100663912                  /opt/apache24/lib/libaprutil-1.so.0.6.3
7f52ffa25000-7f52ffa26000 r--p 0002b000 fd:03 100663912                  /opt/apache24/lib/libaprutil-1.so.0.6.3
7f52ffa26000-7f52ffa27000 rw-p 0002c000 fd:03 100663912                  /opt/apache24/lib/libaprutil-1.so.0.6.3
7f52ffa27000-7f52ffa87000 r-xp 00000000 fd:00 4219099                    /usr/lib64/libpcre.so.1.2.0
7f52ffa87000-7f52ffc87000 ---p 00060000 fd:00 4219099                    /usr/lib64/libpcre.so.1.2.0
7f52ffc87000-7f52ffc88000 r--p 00060000 fd:00 4219099                    /usr/lib64/libpcre.so.1.2.0
7f52ffc88000-7f52ffc89000 rw-p 00061000 fd:00 4219099                    /usr/lib64/libpcre.so.1.2.0
7f52ffc89000-7f52ffcab000 r-xp 00000000 fd:00 4194411                    /usr/lib64/ld-2.17.so
7f52ffe55000-7f52ffe9d000 rw-p 00000000 00:00 0
7f52ffea8000-7f52ffea9000 rw-p 00000000 00:00 0
7f52ffea9000-7f52ffeaa000 rw-p 00000000 00:00 0
7f52ffeaa000-7f52ffeab000 r--p 00021000 fd:00 4194411                    /usr/lib64/ld-2.17.so
7f52ffeab000-7f52ffeac000 rw-p 00022000 fd:00 4194411                    /usr/lib64/ld-2.17.so
7f52ffeac000-7f52ffead000 rw-p 00000000 00:00 0
7ffd059a9000-7ffd059ca000 rw-p 00000000 00:00 0                          [stack]
7ffd059e6000-7ffd059e8000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]

We can reliably reproduce the issue when shutting down Apache. If we disable the metrics endpoint, the problem disappears reliably.

Any idea what the problem could be?

[zandbelt]

ok we'll take a look; can you let us know the version of mod_auth_openidc that you're on and the platform?

[zandbelt]

we were finally able to find the root cause and address it in 16d844f and the fix will be included in the upcoming 2.4.16.3

[studersi]

Good to hear, I will let you know whether this solves our issue 👍

[studersi]

So, we checked with 2.4.16.3 and 2.4.16.5. It looks like there is still an issue but the behaviour has changed. We get the following log entries now:

corrupted size vs. prev_size while consolidating

[2024-11-13 15:25:55.397712] [auth_openidc:trace1] - - oidc_cache_shm_destroy: destroy: 55ff14370298 (shm=55ff143702d0,s=55ff112fa7b0, p=0)                                                 
[2024-11-13 15:25:55.397748] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55ff143702b0 (m=55ff14554b58,s=55ff112fa7b0, p=0)                                                    
[2024-11-13 15:25:55.397754] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55ff14554c80 (m=55ff14554dd0,s=55ff112fa7b0, p=0)                                                    
[2024-11-13 15:25:55.414685] [auth_openidc:trace1] - - oidc_cache_shm_destroy: destroy: 55ff14370298 (shm=55ff143702d0,s=55ff112fa7b0, p=0)                                                 
[2024-11-13 15:25:55.414728] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55ff143702b0 (m=55ff14554b58,s=55ff112fa7b0, p=0)                                                    
[2024-11-13 15:25:55.414734] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55ff14554c80 (m=55ff14554dd0,s=55ff112fa7b0, p=0)                                                    
[2024-11-13 15:25:58.529856] [mpm_event:notice] - - AH00491: caught SIGTERM, shutting down
[2024-11-13 15:25:58.551004] [auth_openidc:trace1] - - oidc_cache_shm_destroy: destroy: 55ff14370298 (shm=55ff143702d0,s=55ff112fa7b0, p=1)
[2024-11-13 15:25:58.551154] [auth_openidc:debug] - - oidc_cache_shm_destroy: apr_shm_destroy returned: 0
[2024-11-13 15:25:58.551164] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55ff143702b0 (m=55ff14554b58,s=55ff112fa7b0, p=1)
[2024-11-13 15:25:58.551183] [auth_openidc:debug] - - oidc_cache_mutex_destroy: apr_global_mutex_destroy/apr_proc_mutex_destroy returned :0
[2024-11-13 15:25:58.551196] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55ff14554c80 (m=55ff14554dd0,s=55ff112fa7b0, p=1)
[2024-11-13 15:25:58.551246] [auth_openidc:debug] - - oidc_cache_mutex_destroy: apr_global_mutex_destroy/apr_proc_mutex_destroy returned :0
[2024-11-13 15:26:03.377444] [auth_openidc:info] - - mod_auth_openidc-2.4.16.5 - shutdown
corrupted size vs. prev_size while consolidating

Disabling the Metrics endpoints reliably prevents this error during shutdown:

[2024-11-13 15:28:57.089423] [auth_openidc:trace1] - - oidc_cache_shm_destroy: destroy: 55cf992eee00 (shm=55cf992eee38,s=55cf9870c7b0, p=0)                                                 
[2024-11-13 15:28:57.089461] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55cf992eee18 (m=55cf9b8aaf98,s=55cf9870c7b0, p=0)                                                    
[2024-11-13 15:28:57.089467] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55cf9b8ab0c0 (m=55cf9b8ab210,s=55cf9870c7b0, p=0)                                                    
[2024-11-13 15:28:57.091792] [auth_openidc:trace1] - - oidc_cache_shm_destroy: destroy: 55cf992eee00 (shm=55cf992eee38,s=55cf9870c7b0, p=0)                                                 
[2024-11-13 15:28:57.091826] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55cf992eee18 (m=55cf9b8aaf98,s=55cf9870c7b0, p=0)                                                    
[2024-11-13 15:28:57.091831] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55cf9b8ab0c0 (m=55cf9b8ab210,s=55cf9870c7b0, p=0)                                                    
[2024-11-13 15:28:57.416075] [mpm_event:notice] - - AH00491: caught SIGTERM, shutting down
[2024-11-13 15:28:57.436797] [auth_openidc:trace1] - - oidc_cache_shm_destroy: destroy: 55cf992eee00 (shm=55cf992eee38,s=55cf9870c7b0, p=1)
[2024-11-13 15:28:57.436958] [auth_openidc:debug] - - oidc_cache_shm_destroy: apr_shm_destroy returned: 0
[2024-11-13 15:28:57.436973] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55cf992eee18 (m=55cf9b8aaf98,s=55cf9870c7b0, p=1)
[2024-11-13 15:28:57.436995] [auth_openidc:debug] - - oidc_cache_mutex_destroy: apr_global_mutex_destroy/apr_proc_mutex_destroy returned :0
[2024-11-13 15:28:57.437003] [auth_openidc:trace1] - - oidc_cache_mutex_destroy: init: 55cf9b8ab0c0 (m=55cf9b8ab210,s=55cf9870c7b0, p=1)
[2024-11-13 15:28:57.437011] [auth_openidc:debug] - - oidc_cache_mutex_destroy: apr_global_mutex_destroy/apr_proc_mutex_destroy returned :0
[2024-11-13 15:28:57.437039] [auth_openidc:info] - - mod_auth_openidc-2.4.16.5 - shutdown

[zandbelt]

hmm, it would really help if you could send us your complete config since we are not able to reproduce ourselves