mod_passenger (passengerAgent) segment fault when start apache

[flight1976]

Question 1: What is the problem?
mod_passenger (passengerAgent) segment fault when start/restart apache

• What is the expected behavior?
  When start/restart apache, dmesg don't generate passengerAgent segment fault error message

• What is the actual behavior?
  When start/restart apache(or daily logrotate) , dmesg generate passengerAgent segment fault error message

• How can we reproduce it?
  install CentOS 8.2 + EPEL repo
  sudo curl --fail -sSLo /etc/yum.repos.d/passenger.repo https://oss-binaries.phusionpassenger.com/yum/definitions/el-passenger.repo
  sudo yum install -y mod_passenger
  sudo systemctl restart httpd
  after restart httpd, dmesg will generate error message

/var/log/httpd/error_log:

[Mon Nov 02 22:36:17.379753 2020] [suexec:notice] [pid 6801:tid 140051464771904] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[ N 2020-11-02 22:36:17.4020 6803/T1 age/Wat/WatchdogMain.cpp:1373 ]: Starting Passenger watchdog...
[ N 2020-11-02 22:36:17.4202 6806/T1 age/Cor/CoreMain.cpp:1340 ]: Starting Passenger core...
[ N 2020-11-02 22:36:17.4204 6806/T1 age/Cor/CoreMain.cpp:256 ]: Passenger core running in multi-application mode.
[ N 2020-11-02 22:36:17.4264 6806/T1 age/Cor/CoreMain.cpp:1015 ]: Passenger core online, PID 6806

[ N 2020-11-02 22:36:17.4412 6806/T9 age/Cor/CoreMain.cpp:671 ]: Signal received. Gracefully shutting down... (send signal 2 more time(s) to force shutdown)
[ N 2020-11-02 22:36:17.4412 6806/T1 age/Cor/CoreMain.cpp:1246 ]: Received command to shutdown gracefully. Waiting until all clients have disconnected...
[ N 2020-11-02 22:36:17.4414 6806/T9 Ser/Server.h:902 ]: [ServerThr.1] Freed 0 spare client objects
[ N 2020-11-02 22:36:17.4414 6806/T9 Ser/Server.h:558 ]: [ServerThr.1] Shutdown finished
[ N 2020-11-02 22:36:17.4415 6806/Tc Ser/Server.h:902 ]: [ApiServer] Freed 0 spare client objects
[ N 2020-11-02 22:36:17.4415 6806/Tc Ser/Server.h:558 ]: [ApiServer] Shutdown finished
[ N 2020-11-02 22:36:17.4415 6806/Tb Ser/Server.h:902 ]: [ServerThr.2] Freed 0 spare client objects
[ N 2020-11-02 22:36:17.4415 6806/Tb Ser/Server.h:558 ]: [ServerThr.2] Shutdown finished
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using localhost.localdomain. Set the 'ServerName' directive globally to suppress this message
[Mon Nov 02 22:36:17.459545 2020] [lbmethod_heartbeat:notice] [pid 6801:tid 140051464771904] AH02282: No slotmem from mod_heartmonitor
[Mon Nov 02 22:36:17.460149 2020] [http2:warn] [pid 6801:tid 140051464771904] AH02951: mod_ssl does not seem to be enabled
[ N 2020-11-02 22:36:17.4818 6828/T1 age/Wat/WatchdogMain.cpp:1373 ]: Starting Passenger watchdog...
[ N 2020-11-02 22:36:17.4982 6831/T1 age/Cor/CoreMain.cpp:1340 ]: Starting Passenger core...
[ N 2020-11-02 22:36:17.4983 6831/T1 age/Cor/CoreMain.cpp:256 ]: Passenger core running in multi-application mode.
[ N 2020-11-02 22:36:17.5034 6831/T1 age/Cor/CoreMain.cpp:1015 ]: Passenger core online, PID 6831
[Mon Nov 02 22:36:17.507018 2020] [mpm_event:notice] [pid 6801:tid 140051464771904] AH00489: Apache/2.4.37 (centos) Phusion_Passenger/6.0.6 configured -- resuming normal operations
[Mon Nov 02 22:36:17.507049 2020] [core:notice] [pid 6801:tid 140051464771904] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
[ N 2020-11-02 22:36:18.4750 6806/T1 age/Cor/TelemetryCollector.h:531 ]: Message from Phusion: End time can not be before or equal to begin time
/usr/include/c++/8/bits/stl_vector.h:932: std::vector<_Tp, _Alloc>::reference std::vector<_Tp, _Alloc>::operator[](std::vector<_Tp, _Alloc>::size_type) [with _Tp = oxt::thread*; _Alloc = std::allocator<oxt::thread*>; std::vector<_Tp, _Alloc>::reference = oxt::thread*&; std::vector<_Tp, _Alloc>::size_type = long unsigned int]: Assertion '__builtin_expect(__n < this->size(), true)' failed.

[ pid=6806, timestamp=1604374578 ] Process aborted! signo=SIGABRT(6), reason=SI_TKILL, signal sent by PID 6806 with UID 0, si_addr=0x1a96, randomSeed=1604374577
[ pid=6806 ] Crash log files will be dumped to /var/tmp/passenger-crash-log.1604374578.QsDeC4 <--- ******* LOOK HERE FOR DETAILS!!! *******
[ pid=6806 ] Date and uname:
Mon Nov  2 22:36:18 EST 2020
Linux 4.18.0-193.28.1.el8_2.x86_64 #1 SMP Thu Oct 22 00:20:22 UTC 2020 x86_64 x86_64
[ pid=6806 ] Phusion Passenger version: 6.0.6
[ pid=6806 ] libc backtrace available!
--------------------------------------
[ pid=6806 ] Backtrace with 18 frames:
ERROR: cannot execute 'ruby "/usr/share/passenger/helper-scripts/backtrace-sanitizer.rb"' for sanitizing the backtrace, writing to stderr directly...
Passenger core[0x4b11a5]
Passenger core[0x4b1d8e]
Passenger core[0x4b43c9]
/lib64/libpthread.so.0(+0x12dd0)[0x7f1cc1433dd0]
/lib64/libc.so.6(gsignal+0x10f)[0x7f1cbf9b070f]
/lib64/libc.so.6(abort+0x127)[0x7f1cbf99ab25]
Passenger core[0x450a78]
Passenger core[0x688bbb]
Passenger core[0x652d4c]
Passenger core[0x553c64]
Passenger core[0x442dfa]
Passenger core[0x60b478]
Passenger core[0x62d115]
Passenger core[0x54f875]
Passenger core[0x5505f3]
Passenger core[0x4af61d]
/lib64/libc.so.6(__libc_start_main+0xf3)[0x7f1cbf99c6a3]
Passenger core(_start+0x2e)[0x44290e]
--------------------------------------
[ pid=6806 ] Dumping ulimits...
Dumping to /var/tmp/passenger-crash-log.1604374578.QsDeC4/ulimits.log
--------------------------------------
[ pid=6806 ] Open files and file descriptors:
Dumping to /var/tmp/passenger-crash-log.1604374578.QsDeC4/fds.log
--------------------------------------
[ pid=6806 ] Dumping a more detailed backtrace with crash-watch...
Dumping to /var/tmp/passenger-crash-log.1604374578.QsDeC4/backtrace.log
--------------------------------------
[ pid=6806 ] **************** LOOK HERE FOR CRASH DETAILS *****************

[ pid=6806 ] Crash log dumped to this directory:
[ pid=6806 ] /var/tmp/passenger-crash-log.1604374578.QsDeC4

[ pid=6806 ] **************** LOOK ABOVE FOR CRASH DETAILS ****************
[ N 2020-11-02 22:36:20.4995 6831/T5 age/Cor/SecurityUpdateChecker.h:519 ]: Security update check: no update found (next check in 24 hours)

/var/tmp/systemd-private-70d5649d08274f83a989c3b1ed92ea56-httpd.service-eyGbwn/tmp/passenger-crash-log.1604374578.QsDeC4/main.log

[ pid=6806, timestamp=1604374578 ] Process aborted! signo=SIGABRT(6), reason=SI_TKILL, signal sent by PID 6806 with UID 0, si_addr=0x1a96, randomSeed=1604374577
[ pid=6806 ] Crash log files will be dumped to /var/tmp/passenger-crash-log.1604374578.QsDeC4 <--- ******* LOOK HERE FOR DETAILS!!! *******
[ pid=6806 ] Date and uname:
Mon Nov  2 22:36:18 EST 2020
Linux 4.18.0-193.28.1.el8_2.x86_64 #1 SMP Thu Oct 22 00:20:22 UTC 2020 x86_64 x86_64
[ pid=6806 ] Phusion Passenger version: 6.0.6
[ pid=6806 ] libc backtrace available!
--------------------------------------
[ pid=6806 ] Backtrace with 18 frames:
ERROR: cannot execute 'ruby "/usr/share/passenger/helper-scripts/backtrace-sanitizer.rb"' for sanitizing the backtrace, writing to stderr directly...
Passenger core[0x4b11a5]
Passenger core[0x4b1d8e]
Passenger core[0x4b43c9]
/lib64/libpthread.so.0(+0x12dd0)[0x7f1cc1433dd0]
/lib64/libc.so.6(gsignal+0x10f)[0x7f1cbf9b070f]
/lib64/libc.so.6(abort+0x127)[0x7f1cbf99ab25]
Passenger core[0x450a78]
Passenger core[0x688bbb]
Passenger core[0x652d4c]
Passenger core[0x553c64]
Passenger core[0x442dfa]
Passenger core[0x60b478]
Passenger core[0x62d115]
Passenger core[0x54f875]
Passenger core[0x5505f3]
Passenger core[0x4af61d]
/lib64/libc.so.6(__libc_start_main+0xf3)[0x7f1cbf99c6a3]
Passenger core(_start+0x2e)[0x44290e]
--------------------------------------
[ pid=6806 ] Dumping ulimits...
Dumping to /var/tmp/passenger-crash-log.1604374578.QsDeC4/ulimits.log
--------------------------------------
[ pid=6806 ] Open files and file descriptors:
Dumping to /var/tmp/passenger-crash-log.1604374578.QsDeC4/fds.log
--------------------------------------
[ pid=6806 ] Dumping a more detailed backtrace with crash-watch...
Dumping to /var/tmp/passenger-crash-log.1604374578.QsDeC4/backtrace.log
--------------------------------------
[ pid=6806 ] **************** LOOK HERE FOR CRASH DETAILS *****************

[ pid=6806 ] Crash log dumped to this directory:
[ pid=6806 ] /var/tmp/passenger-crash-log.1604374578.QsDeC4

[ pid=6806 ] **************** LOOK ABOVE FOR CRASH DETAILS ****************

Question 2: Passenger version and integration mode:

Your answer:
mod_passenger-6.0.6-1.el8.x86_64 from https://oss-binaries.phusionpassenger.com/yum/passenger/el/8/x86_64

Question 3: OS or Linux distro, platform (including version):

Your answer:
CentOS 8.2, x86_64

Question 4: Passenger installation method:

Your answer:
[ ] RubyGems + Gemfile
[ ] RubyGems, no Gemfile
[ ] Phusion APT repo
[*] Phusion YUM repo
[ ] OS X Homebrew
[ ] source tarball
[ ] Other, please specify:

Question 5: Your app's programming language (including any version managers) and framework (including versions):

Your answer:
ruby-2.5.5-105.module_el8.1.0+214+9be47fd7.x86_64 (from CentOS 8.2) with redmine 4.1.1
Question 6: Are you using a PaaS and/or containerization? If so which one?

Your answer:
stand alone KVM Virtual Machine

Question 7: Anything else about your setup that we should know?

Your answer:

---

We strive for quality and appreciate you taking the time to submit a report! Please note that if you want guaranteed response times and priority issue support we encourage you to join our enterprise customer base. They also provide us with the means to continue our high level of open source support!

[k-peek]

I'm having the same issue, also on CentOS8.

[k-peek]

Here is the backtrace:

#0  0x00007fa741c04c4d in raise () from /lib64/libpthread.so.0
No symbol table info available.
#1  0x00000000004b56ac in Passenger::Agent::Fundamentals::abortHandler(int, siginfo_t*, void*) ()
No symbol table info available.
#2  <signal handler called>
No symbol table info available.
#3  0x00007fa74018170f in raise () from /lib64/libc.so.6
No symbol table info available.
#4  0x00007fa74016bb25 in abort () from /lib64/libc.so.6
No symbol table info available.
#5  0x0000000000450a78 in std::__replacement_assert(char const*, int, char const*, char const*) ()
No symbol table info available.
#6  0x0000000000688bbb in oxt::dynamic_thread_group::interrupt_and_join_all(bool) ()
No symbol table info available.
#7  0x0000000000652d4c in Passenger::ApplicationPool2::Pool::~Pool() ()
No symbol table info available.
#8  0x0000000000553c64 in boost::detail::sp_counted_impl_pd<Passenger::ApplicationPool2::Pool*, boost::detail::sp_ms_deleter<Passenger::ApplicationPool2::Pool> >::dispose() ()
No symbol table info available.
#9  0x0000000000442dfa in boost::detail::sp_counted_base::release() [clone .part.67] ()
No symbol table info available.
#10 0x000000000060b478 in Passenger::Core::ApiServer::ApiServer::~ApiServer()
    ()
No symbol table info available.
#11 0x000000000062d115 in Passenger::Core::WorkingObjects::~WorkingObjects()
    ()
No symbol table info available.
#12 0x000000000054f875 in runCore() ()
No symbol table info available.
#13 0x00000000005505f3 in coreMain(int, char**) ()
No symbol table info available.
#14 0x00000000004af61d in main ()
No symbol table info available.

[CamJN]

Reproduced locally.

Pretty sure this is due to -D_GLIBCXX_ASSERTIONS being added to default rpm build flags. We do indexed access to a vector in interrupt_and_join_all, still need to debug that manually, might be a bug, might be an assertion being too picky, we'll see.

[CamJN]

I've pushed some commits that fix the issue for me locally in my centos8 vm, can someone build from source and let me know if it is fixed for them too? commit 8886155 (or later, if I push more before then)

[flight1976]

I've pushed some commits that fix the issue for me locally in my centos8 vm, can someone build from source and let me know if it is fixed for them too? commit 8886155 (or later, if I push more before then)

Thank you for your assistance.

Report my test result:
build from newest github source -> upgrade passenger and mod_passenger rpm package, mod_passenger still segment fault when restart apache.

upgrade step

cd /tmp
git clone https://github.com/phusion/passenger
cd passenger
git submodule update --init --recursive
cd packaging/rpm
./build -p ../../ -w ~/test -c ~/cache -o output -d el8 -a x86_64 rpm:all
rpm -Uvh passenger-6.0.8-1.el8.x86_64.rpm mod_passenger-6.0.8-1.el8.x86_64.rpm
systemctl restart httpd

backtrace.log
fds.log
main.log
ulimits.log

[CamJN]

Can you also include a full Passenger log with log level set to 7? I added some extra logging to the problem function.

[flight1976]

Can you also include a full Passenger log with log level set to 7? I added some extra logging to the problem function.

systemctl stop httpd
vim /etc/httpd/conf.d/passenger.conf (add PassengerLogLevel 7)
systemctl start httpd

apache error log file as attachment.

apache-error.log

[CamJN]

Thank you so much @flight1976 and everyone else! I pushed a commit 2bfa330 that fixes this crash, turns out I was overlooking an indexed access at the end of the function that was invalid when the list of threads was empty, so now that's bounds checked as well. If you find more crashes in the centos 8 build, please let me know. The assertions redhat added in centos 8 are a good tool for finding issues like this.

[flight1976]

Thank you so much @flight1976 and everyone else! I pushed a commit 2bfa330 that fixes this crash, turns out I was overlooking an indexed access at the end of the function that was invalid when the list of threads was empty, so now that's bounds checked as well. If you find more crashes in the centos 8 build, please let me know. The assertions redhat added in centos 8 are a good tool for finding issues like this.

Apply 2bfa330 and rebuild from source confirm fix the issue for me, thanks for your help. :)