UTF-8 decoding error with 0.9.15.post1 worker on Python 2.7

[faudebert]

While running both worker and master with Buildbot 0.9.15.post1 and Python 2.7, I sometimes got backtraces below.

018-03-07T02:00:54+0100 [HangCheckProtocol,client]   using PTY: False
2018-03-07T02:07:54+0100 [-] Unhandled Error
  Traceback (most recent call last):
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/base.py", line 1243, in run
      self.mainLoop()
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/base.py", line 1252, in mainLoop
      self.runUntilCurrent()
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/base.py", line 878, in runUntilCurrent
      call.func(*call.args, **call.kw)
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/task.py", line 239, in __call__
      d = defer.maybeDeferred(self.f, *self.a, **self.kw)
  --- <exception caught here> ---
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/defer.py", line 150, in maybeDeferred
      result = f(*args, **kw)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 164, in poll
      self.command.addLogfile(self.name, data)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 763, in addLogfile
      self._addToBuffers(('log', name), data)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 739, in _addToBuffers
      self._sendBuffers()
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 721, in _sendBuffers
      self._sendMessage(msg)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 667, in _sendMessage
      msg = self._collapseMsg(msg)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 653, in _collapseMsg
      m = bytes2unicode(m, self.builder.unicode_encoding)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/compat.py", line 87, in bytes2unicode
      return text_type(x, encoding, errors)
    File "/usr/lib/python2.7/encodings/utf_8.py", line 16, in decode
      return codecs.utf_8_decode(input, errors, True)
  exceptions.UnicodeDecodeError: 'utf8' codec can't decode bytes in position 9998-9999: unexpected end of data

2018-03-07T02:10:19+0100 [-] sending app-level keepalive
2018-03-07T02:18:28+0100 [-] command finished with signal None, exit code 0, elapsedTime: 1054.394399
2018-03-07T02:18:28+0100 [-] unexpected error in processEnded
  Traceback (most recent call last):
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/process.py", line 985, in maybeCallProcessEnded
      self.reapProcess()
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/process.py", line 350, in reapProcess
      self.processEnded(status)
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/_baseprocess.py", line 52, in processEnded
      self.maybeCallProcessEnded()
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/process.py", line 987, in maybeCallProcessEnded
      _BaseProcess.maybeCallProcessEnded(self)
  --- <exception caught here> ---
    File "/usr/local/lib/python2.7/dist-packages/twisted/internet/_baseprocess.py", line 64, in maybeCallProcessEnded
      proto.processEnded(Failure(reason))
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 250, in processEnded
      self.command.finished(sig, rc)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 774, in finished
      w.stop()
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 129, in stop
      self.poll()
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 164, in poll
      self.command.addLogfile(self.name, data)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 763, in addLogfile
      self._addToBuffers(('log', name), data)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 739, in _addToBuffers
      self._sendBuffers()
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 721, in _sendBuffers
      self._sendMessage(msg)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 667, in _sendMessage
      msg = self._collapseMsg(msg)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/runprocess.py", line 653, in _collapseMsg
      m = bytes2unicode(m, self.builder.unicode_encoding)
    File "/usr/local/lib/python2.7/dist-packages/buildbot_worker/compat.py", line 87, in bytes2unicode
      return text_type(x, encoding, errors)
    File "/usr/lib/python2.7/encodings/utf_8.py", line 16, in decode
      return codecs.utf_8_decode(input, errors, True)
  exceptions.UnicodeDecodeError: 'utf8' codec can't decode byte 0x99 in position 0: invalid start byte

This happens on very log-intensive jobs (verbose buildroot output). After such backtrace occurred, the job is hanging unfinished indefinitely (DockerLatentWorker).

I'm unable to reproduce such issue while running 0.9.10 worker using the same master instance (ie. 0.9.15.post1). I reported a similar issue in #3702 few month ago but it was maybe not related to initial reporter issue.

[congzhangzh]

log file with mix encode will be the reason, have a look at #3852 and #3631