While debugging an issue today that generates a 503 error i tried looking in /a/mw-log/fatal.log, but no error reported. Also no error in exception.log. After poking around i eventually found the error in hhvm.log, but its buried in other useless (in respect to fatal hunting) information:
Apr 2 16:38:34 mw1143: SlowTimer [16038ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163818' WHERE page_id = '4092919' AND (page_touched < '20150402163818') Apr 2 16:38:34 mw1198: SlowTimer [16389ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163818' WHERE page_id = '4092919' AND (page_touched < '20150402163818') Apr 2 16:38:34 mw1188: #012Notice: Undefined index: timestamp in /srv/mediawiki/php-1.25wmf23/extensions/Flow/includes/Formatter/RevisionViewFormatter.php on line 43 Apr 2 16:38:34 mw1190: SlowTimer [16617ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163818' WHERE page_id = '4092919' AND (page_touched < '20150402163818') Apr 2 16:38:34 mw1188: #012Notice: Undefined index: workflowId in /srv/mediawiki/php-1.25wmf23/extensions/Flow/includes/Formatter/RevisionDiffViewFormatter.php on line 52 Apr 2 16:38:34 mw1188: #012Fatal error: Argument 3 passed to Flow\UrlGenerator::diffLink() must be an instance of Flow\Model\UUID, null given in /srv/mediawiki/php-1.25wmf23/extensions/Flow/includes/UrlGenerator.php on line 366 Apr 2 16:38:34 mw1102: #012Notice: Undefined index: timestamp in /srv/mediawiki/php-1.25wmf23/extensions/Flow/includes/Formatter/RevisionViewFormatter.php on line 43 Apr 2 16:38:34 mw1142: SlowTimer [16870ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163818' WHERE page_id = '4092919' AND (page_touched < '20150402163818') Apr 2 16:38:35 mw1102: #012Notice: Undefined index: workflowId in /srv/mediawiki/php-1.25wmf23/extensions/Flow/includes/Formatter/RevisionDiffViewFormatter.php on line 52 Apr 2 16:38:35 mw1102: #012Fatal error: Argument 3 passed to Flow\UrlGenerator::diffLink() must be an instance of Flow\Model\UUID, null given in /srv/mediawiki/php-1.25wmf23/extensions/Flow/includes/UrlGenerator.php on line 366 Apr 2 16:38:35 mw1127: SlowTimer [12844ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163822' WHERE page_id = '4092919' AND (page_touched < '20150402163822') Apr 2 16:38:35 mw1129: SlowTimer [13289ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163822' WHERE page_id = '4092919' AND (page_touched < '20150402163822') Apr 2 16:38:36 mw1228: SlowTimer [13718ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163822' WHERE page_id = '4092919' AND (page_touched < '20150402163822') Apr 2 16:38:36 mw1225: SlowTimer [13871ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163822' WHERE page_id = '4092919' AND (page_touched < '20150402163822') Apr 2 16:38:36 mw1126: SlowTimer [14045ms] at runtime/ext_mysql: slow query: UPDATE /* SqlDataUpdate::invalidatePages Marcus Cyron */ `page` SET page_touched = '20150402163822' WHERE page_id = '4092919' AND (page_touched < '20150402163822')
Fatal errors need to be easy to find and diagnose, can we find some way to get these errors back into fatal.log? We can of course grep through hhvm.log, but that doesn't seem nearly as nice as the old way.