Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Long log lines cause logging to stop for ipdevpoll processes in multiprocess mode #893

Closed
jmbredal opened this issue Jan 17, 2017 · 3 comments

Comments

@jmbredal
Copy link
Collaborator

jmbredal commented Jan 17, 2017

The current mode of operation for ipdevpoll's multiprocess mode is that a master process starts, spawning a set of subprocesses for each of the configured jobs. The stderr/stdout output from these subprocesses is logged to ipdevpoll.conf by the master process.

If one of the subprocesses issue an output line that happens to be larger than 16384 characters long (could happen in some debug cases, I guess), the master process will disconnect its pipe to the child process, and logging from the subprocess stops completely.

This is a limitation of the process monitor implementation in the Twisted library. It could be remedied by simply increasing the MAX_LENGTH value configured in the twisted.runner.procmon.LineLogger class.

A traceback from ipdevpoll.log when this happens may look like this:

Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 88, in callWithLogger
return callWithContext({"system": lp}, func, *args, **kw)
File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 73, in callWithContext
return context.call({ILogContext: newCtx}, func, *args, **kw)
File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
return self.currentContext().callWithContext(ctx, func, *args, **kw)
File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
return func(*args,**kw)
--- ---
File "/usr/lib/python2.7/dist-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
why = selectable.doRead()
File "/usr/lib/python2.7/dist-packages/twisted/internet/process.py", line 257, in doRead
return fdesc.readFromFD(self.fd, self.dataReceived)
File "/usr/lib/python2.7/dist-packages/twisted/internet/fdesc.py", line 94, in readFromFD
callback(output)
File "/usr/lib/python2.7/dist-packages/twisted/internet/process.py", line 260, in dataReceived
self.proc.childDataReceived(self.name, data)
File "/usr/lib/python2.7/dist-packages/twisted/internet/process.py", line 887, in childDataReceived
self.proto.childDataReceived(name, data)
File "/usr/lib/python2.7/dist-packages/twisted/internet/protocol.py", line 593, in childDataReceived
self.errReceived(data)
File "/usr/lib/python2.7/dist-packages/twisted/runner/procmon.py", line 41, in outReceived
self.output.dataReceived(data)
File "/usr/lib/python2.7/dist-packages/twisted/protocols/basic.py", line 563, in dataReceived
return self.lineLengthExceeded(line)
File "/usr/lib/python2.7/dist-packages/twisted/protocols/basic.py", line 648, in lineLengthExceeded
return self.transport.loseConnection()
exceptions.AttributeError: DummyTransport instance has no attribute 'loseConnection'


Imported from Launchpad using lp2gh.

@jmbredal
Copy link
Collaborator Author

(by mbrekkevold)
fix here: https://nav.uninett.no/hg/nav/rev/55b22df20275

@jmbredal jmbredal added this to the 4.6.1 milestone Jan 17, 2017
@lunkwill42 lunkwill42 added the bug label Jan 25, 2017
@lunkwill42
Copy link
Member

git version of fix: 680c7ff

@jmbredal
Copy link
Collaborator Author

Translated changeset references:
https://nav.uninett.no/hg/nav/rev/55b22df20275: 680c7ff

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants