hhvm.log: file not found on Fluorine
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	Dereckson
	Aug 31 2016, 1:47 PM

Description

We didn't have an Icinga notification for this one.

Details

Related Changes in Gerrit:

	Subject	Repo	Branch	Lines +/-
	Follow-up I6df802b9: Fix udp2log's demux.py	operations/puppet	production	+1 -1

Customize query in gerrit

Revisions and Commits

rOPUP Wikimedia Puppet
	rOPUPde93e39b978a Remove the hard-coded /a/mw-log references scattered around everywhere

Related Objects
Search...

		Status	Subtype	Assigned	Task
		Resolved		hashar	T142117 MW-1.28.0-wmf.17 deployment blockers
		Resolved		• AlexMonk-WMF	T144389 /a/mw-log/hhvm.log: file not found on Fluorine

Event Timeline

Dereckson created this task.Aug 31 2016, 1:47 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptAug 31 2016, 1:47 PM

Dereckson mentioned this in T128796: rack new mw log host - sinistra.Aug 31 2016, 4:16 PM

Hmm...but logstash fatalmonitor still appears to be working fine.

I definitely lean on fatalmonitor a lot during SWATs.

so now the output of fatalmonitor on fluorine is:

Every 2.0s: tail -n 1000 /a/mw-log/hhvm.log |                                                                                                                 Wed Aug 31 18:36:06 2016

tail: cannot open `/a/mw-log/hhvm.log' for reading: No such file or directory

This is pretty important and (hopefully not) indicative of something else going on.

Restricted Application added subscribers: Jay8g, Luke081515, TerraCodes. · View Herald TranscriptAug 31 2016, 6:41 PM

hashar added a parent task: T142117: MW-1.28.0-wmf.17 deployment blockers.Aug 31 2016, 6:51 PM

I have made it a blocker of tonight deployment, tailing from log file give a way faster response time compared to logstash. But maybe I am getting old.

On fluorine ps -u udp2log f shows a wild range of python and sh process in zombie mode, but I think that is a known issue.

The process has been running for a while and there is a pipe relaying to logstash1001.eqiad.wmnet which seems to work. https://logstash.wikimedia.org/ mediawiki-errors has a bunch of messages.

Thus it seems the messages are properly relayed to fluorine but somehow are not written to disk. Maybe that is one of the sh that is defunct, I can't remember offhand how and whether demux.py write to disk directly.

logrotate went at 6:25

stat hhvm.log-20160831.gz has:

Access: 2016-08-31 18:57:18.977526992 +0000
Modify: 2016-08-31 06:25:13.000000000 +0000
Change: 2016-08-31 08:19:13.792872275 +0000

stat apache2.log-20160831.gz

Access: 2016-08-30 17:41:16.000000000 +0000
Modify: 2016-08-31 06:25:23.000000000 +0000
Change: 2016-08-31 06:26:53.452036313 +0000

The root dir /a/mw-log barely has anything.

Maybe that is a puppet change that broke it.

/etc/rsyslog.d/30-remote-syslog.conf has been changed at Aug 31 13:43

hashar added a comment.Aug 31 2016, 7:21 PM

This comment was removed by hashar.

After a bunch of investigation with @bd808 @ArielGlenn @Krenair :

Aug 30 19:48 /usr/local/bin/demux.py

Most probably caused by de93e39b978ae213c61b0ef76ac14e0240158110

Change 307812 had a related patch set uploaded (by Alex Monk):
Follow-up I6df802b9: Fix udp2log's demux.py

https://gerrit.wikimedia.org/r/307812

gerritbot added a project: Patch-For-Review.Aug 31 2016, 7:42 PM

Change 307812 merged by ArielGlenn:
Follow-up I6df802b9: Fix udp2log's demux.py