Thanks, all. I'm still working on this.
PHP error logging
php.ini does already have
error_reporting = E_ALL & ~E_DEPRECATED & ~E_STRICT
. The logging is actually working; I verified this with a bad script. But no PHP errors are logged at the time of the php-fpm crashes.
PHP config
Almost everything is set to the
lang/php72 port's php.ini-production defaults. I only edited php.ini to enable the log settings mentioned previously, plus a few opcache settings. The crashes happen regardless of whether opcache is installed.
MySQL connection & query logging
I was looking in the wrong place for the MySQL query log; I had
log-output=TABLE
in my.cnf, and needed it to be
log-output=FILE
. (When it was TABLE, the log was going into a database table, although a file was still created somehow; it was just mostly empty).
Generating crashes with MediaWiki
I can get php-fpm to crash about 10–20% of the time by editing a MediaWiki article. MediaWiki runs MySQL queries via multiple socket connections—2 or 3 at a time, 11 connections total for a typical edit. The MYSQL log shows that when I get a crash, it happens consistently at the same place every time. It's actually not immediately upon connection, rather it's while running some queries.
Here is the last message in the log when there's a crash:
SQL:
SELECT /* LCStoreDB::get */ lc_value FROM `mw_l10n_cache` WHERE lc_lang = 'en' AND lc_key = 'magicWords' LIMIT 1
When there's no crash, the next message is this:
SQL:
SELECT /* WikiPage::pageData */ page_id,page_namespace,page_title,page_restrictions,page_is_redirect,page_is_new,page_random,page_touched,page_links_updated,page_latest,page_len,page_content_model FROM `mw_page` WHERE page_namespace = '2' AND page_title = 'Mjb/FreeBSD_on_BeagleBone_Black/Additional_software' LIMIT 1;
Both of these are benign queries which I can run from the
mysql
command-line client with no problems. The data returned by the queries is very short.
When there's no crash, no new connections are made for a while, and the only other open connection at the time these queries are running is idle. The next thing which that 2nd connection will do is this:
SQL:
SELECT /* SqlBagOStuff::getMulti */ keyname,value,exptime FROM `mw_objectcache` WHERE keyname = 'OffsetDB-mw_:messages:en'
...which is again, nothing notable; I can run it myself without incident (other than the binary value data turning my console to gibberish).
So I am unsure what to make of this. It's crashing at random in a consistent spot, but nothing too demanding is happening at that particular moment, as far as I can tell.
Other ways to crash php-fpm?
I only have one other app using MySQL: Tiny Tiny RSS. Before I upgraded it to the latest version, it was crashing php-fpm consistently when I tried to do anything with it. But now that I am using the current port, all is well; it does not trigger the crash, so I can't use it to try to figure out what it might have in common with MediaWiki.
Martin's suggestion for a PHP test script was helpful. I made it open 2 connections and hit the same tables, but I am unable to generate any crashes with it:
PHP:
<?php
$dbname = "foo";
$dbuser = "foo";
$dbpass = "foo";
$pagename = 'Mjb/FreeBSD_on_BeagleBone_Black/Additional_software';
echo '<h1>Testing...</h1>';
try {
$dsn = "mysql:host=localhost;dbname=$dbname";
$dbh = new PDO($dsn, $dbuser, $dbpass, array(PDO::ATTR_ERRMODE => PDO::ERRMODE_EXCEPTION));
$dbh2 = new PDO($dsn, $dbuser, $dbpass, array(PDO::ATTR_ERRMODE => PDO::ERRMODE_EXCEPTION));
$query = "SELECT old_text FROM mw_text WHERE old_id IN (SELECT rev_text_id FROM mw_revision LEFT JOIN mw_page ON page_latest = rev_id WHERE page_title LIKE '" . $pagename . "');";
$query2 = "SELECT /* WikiPage::pageData */ page_id,page_namespace,page_title,page_restrictions,page_is_redirect,page_is_new,page_random,page_touched,page_links_updated,page_latest,page_len,$
$sth = $dbh->query($query);
$result = $sth->fetch(PDO::FETCH_OBJ);
$raw_content = $result->old_text;
echo '<pre style="margin: 3em; padding: 1em; border: 1px solid black; background: #eee; color: #000; white-space: pre-wrap;">';
echo str_replace('<','<',str_replace('&','&',$raw_content));
echo '</pre>';
$sth2 = $dbh2->query($query2);
$result = $sth2->fetchAll();
$raw_content = print_r($result, TRUE);
echo '<pre style="margin: 3em; padding: 1em; border: 1px solid black; background: #eee; color: #000; white-space: pre-wrap;">';
echo str_replace('<','<',str_replace('&','&',$raw_content));
echo '</pre>';
$sth = null;
$dbh = null;
$dbh2 = null;
} catch (PDOException $e){
echo $e->getMessage();
}
?>
MySQL configuration
Because this is running on a BeagleBone Black, I have some resource limits in my.cnf to try to keep MySQL from hogging precious RAM. However, I'm pretty sure a crash (in php-fpm or anywhere else) should not be the expected outcome if some values are too low. Nevertheless, here's what I am using, and suggestions for further tuning appreciated:
Code:
# $FreeBSD: branches/2019Q1/databases/mysql57-server/files/my.cnf.sample.in 414707 2016-05-06 14:39:59Z riggs $
[client]
port = 3306
socket = /tmp/mysql.sock
[mysql]
prompt = \u@\h [\d]>\_
no_auto_rehash
[mysqld]
user = mysql
port = 3306
socket = /tmp/mysql.sock
bind-address = 127.0.0.1
basedir = /usr/local
datadir = /var/db/mysql
tmpdir = /var/db/mysql_tmpdir
slave-load-tmpdir = /var/db/mysql_tmpdir
secure-file-priv = /var/db/mysql_secure
log-bin = mysql-bin
#log-output = TABLE
log-output = FILE
master-info-repository = TABLE
relay-log-info-repository = TABLE
relay-log-recovery = 1
slow-query-log = 1
server-id = 1
sync_binlog = 1
sync_relay_log = 1
#binlog_cache_size = 16M
binlog_cache_size = 4K
expire_logs_days = 30
default_password_lifetime = 0
enforce-gtid-consistency = 1
gtid-mode = ON
safe-user-create = 1
lower_case_table_names = 1
explicit-defaults-for-timestamp = 1
myisam-recover-options = BACKUP,FORCE
open_files_limit = 32768
table_open_cache = 16384
table_definition_cache = 8192
net_retry_count = 16384
#key_buffer_size = 256M
key_buffer_size = 8M
max_allowed_packet = 64M
query_cache_type = 0
query_cache_size = 0
long_query_time = 0.5
#innodb_buffer_pool_size = 1G
innodb_buffer_pool_size = 5M
innodb_data_home_dir = /var/db/mysql
innodb_log_group_home_dir = /var/db/mysql
#innodb_data_file_path = ibdata1:128M:autoextend
innodb_data_file_path = ibdata1:12M:autoextend
#innodb_temp_data_file_path = ibtmp1:128M:autoextend
innodb_temp_data_file_path = ibtmp1:12M:autoextend
innodb_flush_method = O_DIRECT
innodb_log_file_size = 256M
innodb_log_buffer_size = 256K
innodb_write_io_threads = 8
innodb_read_io_threads = 8
innodb_autoinc_lock_mode = 2
skip-symbolic-links
# all of the following added by mjb
max_connections=20
thread_cache_size=0
host_cache_size=0
innodb_ft_cache_size=1600000
innodb_ft_total_cache_size=32000000
thread_stack=256K
sort_buffer_size=32K
read_buffer_size=8200
read_rnd_buffer_size=8200
max_heap_table_size=16K
tmp_table_size=1K
bulk_insert_buffer_size=0
join_buffer_size=128
net_buffer_length=1K
innodb_sort_buffer_size=64K
binlog_stmt_cache_size=4K
general_log = 1
[mysqldump]
max_allowed_packet = 256M
quote_names
quick
(Variations from the my.cnf.sample defaults are all noted with comments.)
Next steps?
Could it be some kind of database corruption? But
mysql_check
says everything is OK.
Still wish I could figure out how to get php-fpm to dump core. Someone could then take a look at it for me.