Page MenuHomePhabricator

Array to string conversion in MWTimestamp.php causes HHVM 3.9 to segfault (works in HHVM 3.12)
Closed, DeclinedPublic

Description

An array to string conversion error in MWTimestamp.php causes HHVM 3.9 (from their jessie-lts-3.9 dl.hhvm.com repo) to segfault and crash. Since my knowledge of HHVM is very limited (and the stacktraces do not really show an array was passed?), I hope someone knows more about this.

HHVM crashes here for no reason every few hours (and debugging is really hard) since I upgraded to MediaWiki 1.26, so I guess this is the reason it does. It looks it's not easy to reproduce anyway.

/var/log/syslog:

[yes, I restarted HHVM here because it crashed]
Jan 13 16:51:46 mw1 systemd[1]: Started LSB: Starts The HHVM FastCGI Daemon.
Jan 13 16:51:48 mw1 hhvm: #012Notice: Array to string conversion in /srv/mediawiki/w/includes/MWTimestamp.php on line 152
Jan 13 16:51:48 mw1 hhvm: #012Notice: Array to string conversion in /srv/mediawiki/w/includes/MWTimestamp.php on line 152
Jan 13 16:51:48 mw1 hhvm: #012Notice: Array to string conversion in /srv/mediawiki/w/includes/MWTimestamp.php on line 152
Jan 13 16:51:48 mw1 hhvm: #012Notice: Array to string conversion in /srv/mediawiki/w/includes/MWTimestamp.php on line 152
Jan 13 16:51:48 mw1 hhvm: #012Notice: Array to string conversion in /srv/mediawiki/w/includes/MWTimestamp.php on line 152
Jan 13 16:51:48 mw1 hhvm: #012Notice: Array to string conversion in /srv/mediawiki/w/includes/MWTimestamp.php on line 152
Jan 13 16:51:48 mw1 hhvm: Core dumped: Segmentation fault
Jan 13 16:51:48 mw1 hhvm: Stack trace in /var/log/hhvm/stacktrace.18489.log

/var/log/hhvm/stacktrace.18489.log:

PHP Stacktrace:

#0  DateTimeZone->__construct(GMT) called at [/srv/mediawiki/w/includes/MWTimestamp.php:152]
#1  MWTimestamp->setTimestamp(0) called at [/srv/mediawiki/w/includes/MWTimestamp.php:62]
#2  MWTimestamp->__construct(0) called at [/srv/mediawiki/w/includes/GlobalFunctions.php:2425]
#3  wfTimestamp(2) called at [/srv/mediawiki/w/includes/debug/logger/LegacyLogger.php:306]
#4  MediaWiki\Logger\LegacyLogger::formatAsWfDebugLog(redis, Creating a new RedisConnectionPool instance with id [random string here]., Array) called at [/srv/mediawiki/w/includes/debug/logger/LegacyLogger.php:217]
#5  MediaWiki\Logger\LegacyLogger::format(redis, Creating a new RedisConnectionPool instance with id [random string here]., Array) called at [/srv/mediawiki/w/includes/debug/logger/LegacyLogger.php:90]
#6  MediaWiki\Logger\LegacyLogger->log(debug, Creating a new RedisConnectionPool instance with id [random string here]., Array) called at [/srv/mediawiki/w/vendor/psr/log/Psr/Log/AbstractLogger.php:118]
#7  Psr\Log\AbstractLogger->debug(Creating a new RedisConnectionPool instance with id [random string here].) called at [/srv/mediawiki/w/includes/clientpool/RedisConnectionPool.php:163]
#8  RedisConnectionPool::singleton(Array) called at [/srv/mediawiki/w/includes/objectcache/RedisBagOStuff.php:74]
#9  RedisBagOStuff->__construct(Array) called at [/srv/mediawiki/w/includes/objectcache/ObjectCache.php:150]
#10 ObjectCache::newFromParams(Array) called at [/srv/mediawiki/w/includes/objectcache/ObjectCache.php:124]
#11 ObjectCache::newFromId(redis) called at [/srv/mediawiki/w/includes/objectcache/ObjectCache.php:88]
#12 ObjectCache::getInstance(redis) called at [/srv/mediawiki/w/includes/GlobalFunctions.php:3988]
#13 wfGetMainCache() called at [/srv/mediawiki/w/includes/Setup.php:639]
#14 include(/srv/mediawiki/w/includes/Setup.php) called at [/srv/mediawiki/w/includes/WebStart.php:137]
#15 include(/srv/mediawiki/w/includes/WebStart.php) called at [/srv/mediawiki/w/index.php:38]

The actual ErrorException thrown by MediaWiki:

2016-01-13 16:51:48 mw1 allthetropeswiki: [7b65c852] /wiki/Naughty_Tentacles   ErrorException from line 152 of /srv/mediawiki/w/includes/MWTimestamp.php: PHP Notice: Array to string conversion
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array, array)
#1 /srv/mediawiki/w/includes/MWTimestamp.php(152): DateTimeZone->__construct(string)
#2 /srv/mediawiki/w/includes/MWTimestamp.php(62): MWTimestamp->setTimestamp(integer)
#3 /srv/mediawiki/w/includes/GlobalFunctions.php(2425): MWTimestamp->__construct(integer)
#4 /srv/mediawiki/w/includes/debug/logger/LegacyLogger.php(306): wfTimestamp(integer)
#5 /srv/mediawiki/w/includes/debug/logger/LegacyLogger.php(217): MediaWiki\Logger\LegacyLogger::formatAsWfDebugLog(string, string, array)
#6 /srv/mediawiki/w/includes/debug/logger/LegacyLogger.php(90): MediaWiki\Logger\LegacyLogger::format(string, string, array)
#7 /srv/mediawiki/w/vendor/psr/log/Psr/Log/AbstractLogger.php(118): MediaWiki\Logger\LegacyLogger->log(string, string, array)
#8 /srv/mediawiki/w/includes/clientpool/RedisConnectionPool.php(163): Psr\Log\AbstractLogger->debug(string)
#9 /srv/mediawiki/w/includes/objectcache/RedisBagOStuff.php(74): RedisConnectionPool::singleton(array)
#10 /srv/mediawiki/w/includes/objectcache/ObjectCache.php(150): RedisBagOStuff->__construct(array)
#11 /srv/mediawiki/w/includes/objectcache/ObjectCache.php(124): ObjectCache::newFromParams(array)
#12 /srv/mediawiki/w/includes/objectcache/ObjectCache.php(88): ObjectCache::newFromId(string)
#13 /srv/mediawiki/w/includes/GlobalFunctions.php(3988): ObjectCache::getInstance(string)
#14 /srv/mediawiki/w/includes/Setup.php(639): wfGetMainCache()
#15 /srv/mediawiki/w/includes/WebStart.php(137): include(string)
#16 /srv/mediawiki/w/index.php(38): include(string)

HHVM config (php.ini + server.ini):

; php options
include_path = ".:/usr/share/php"
session.save_handler = files
session.save_path = /var/lib/hhvm/sessions
session.gc_maxlifetime = 1440
memory_limit = 700M

; hhvm specific
hhvm.log.level = Warning
hhvm.log.always_log_unhandled_exceptions = true
hhvm.log.runtime_error_reporting_level = 8191
hhvm.mysql.typed_results = false
; php options

pid = /var/run/hhvm/pid

; hhvm general

hhvm.server.port = 9000
hhvm.server.type = fastcgi
hhvm.server.default_document = index.php
hhvm.repo.central.path = /var/run/hhvm/hhvm.hhbc
hhvm.eval.perf_pid_map = false
hhvm.jit = false

; hhvm logging

hhvm.debug.core_dump_report = true
hhvm.debug.core_dump_report_directory = /var/log/hhvm
hhvm.debug.core_dump_email = HIDDEN
hhvm.debug.full_backtrace = true
hhvm.debug.profiler_output_dir = /tmp
hhvm.debug.server_stack_trace = true
hhvm.debug.server_error_message = true
hhvm.error_handling.call_user_handler_on_fatals = true
hhvm.log.level = Error
hhvm.log.native_stack_trace = true
hhvm.log.use_syslog = true
hhvm.log.injected_stack_trace = true
hhvm.log.use_log_file = true
hhvm.log.file = /var/log/hhvm/error.log
hhvm.log.always_log_unhandled_exceptions = true

; hhvm admin server

hhvm.admin_server.port = 9001
hhvm.admin_server.password = HIDDEN

I also wonder why I can't found any core dumps in /var/log/hhvm, while syslog says a core was dumped.

Oh, and I just installed hhvm-dbg (3.9 too) after this happened. It's much slower than regular HHVM (and it's running in production which is even worse), but perhaps it would be useful for some better logs (e.g. gdb backtrace), idk.

Event Timeline

Southparkfan raised the priority of this task from to Needs Triage.
Southparkfan updated the task description. (Show Details)
Southparkfan added subscribers: Southparkfan, ori.

Downgrading to HHVM 3.6 seems to fix this (at least it didn't crash immediately).

I understand that there aren't many HHVM experts out here, but I really think this issue should be prioritized, because HHVM 3.6 support is going to end soon - the WMF needs to upgrade to 3.9 or 3.12 (3.12 likely). It looks like the amount of errors got significantly worse(?) in T126871 (3.12).

@Southparkfan hi Wikimedia foundation have upgraded to hhvm 3.12. could you see if hhvm 3.12 works for you please.

@Paladox I've already upgraded to HHVM 3.12, which seems to work.

@Southparkfan ok thanks. If it works for you should we resolve this task please.

Aklapper renamed this task from Array to string conversion in MWTimestamp.php causes HHVM 3.9 to segfault to Array to string conversion in MWTimestamp.php causes HHVM 3.9 to segfault (works in HHVM 3.12).Jul 25 2016, 2:34 PM
Aklapper closed this task as Declined.
Aklapper set Security to None.