Opened 4 years ago

Closed 3 years ago

Last modified 2 years ago

#7427 defect closed fixed (fixed)

FileBodyProducer + LengthEnforcingConsumer cause exceptions in cooperator loop

Reported by: immerrr Owned by:
Priority: normal Milestone:
Component: web Keywords:
Cc: jknight Branch:
Author:

Description

I'm attaching a minimal example that reproduces the described behaviour. Here's how the stacktrace looks like:

Traceback (most recent call last):
Failure: twisted.web._newclient.RequestGenerationFailed: [<twisted.python.failure.Failure <class 'twisted.internet.defer.CancelledError'>>]
Unhandled Error
Traceback (most recent call last):
  File "/home/immerrr/twisted_reproduce.py", line 25, in <module>
    task.react(main)
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/task.py", line 858, in react
    _reactor.run()
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/base.py", line 1192, in run
    self.mainLoop()
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/base.py", line 1201, in mainLoop
    self.runUntilCurrent()
--- <exception caught here> ---
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/base.py", line 824, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/task.py", line 607, in _tick
    taskObj._oneWorkUnit()
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/task.py", line 488, in _oneWorkUnit
    self._completeWith(TaskFailed(), Failure())
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/task.py", line 444, in _completeWith
    self._cooperator._removeTask(self)
  File "/home/immerrr/.conda/envs/controlserver/lib/python2.7/site-packages/twisted/internet/task.py", line 580, in _removeTask
    self._tasks.remove(task)
exceptions.ValueError: list.remove(x): x not in list

There seem to be two factors causing this:

  1. FileBodyProducer doesn't stop producing upon cancellation
  1. LengthEnforcingConsumer causes producer to stop twice:
LengthEnforcingConsumer.write
|
+-> producer.stopProducing
|   -> task.stop()
|   -> task._completeWith(...)
|
`- raise ExcessWrite
   -> CooperativeTask._oneWorkUnit
   -> except: (catch exception)
   -> task._completeWith(...)

Attachments (1)

twisted_reproduce.py (661 bytes) - added by immerrr 4 years ago.
minimal example to reproduce the defect

Download all attachments as: .zip

Change History (5)

comment:1 Changed 4 years ago by DefaultCC Plugin

Cc: jknight added

Changed 4 years ago by immerrr

Attachment: twisted_reproduce.py added

minimal example to reproduce the defect

comment:2 Changed 3 years ago by Richard Wall

Hi immerrr

I tried running your script, but didn't see an error with twisted trunk

$ python ../../twisted_reproduce.py

Please confirm.

comment:3 Changed 3 years ago by immerrr

Resolution: fixed
Status: newclosed

This appears to be fixed somewhere between

commit 409d7e66800bb56cb9524e551dc1d8720ccd7185
Author: wsanchez <wsanchez@bbbe8e31-12d6-0310-92fd-ac37d47ddeeb>
Date:   Tue Jun 3 05:20:33 2014 +0000

    Revert r42756: Add feature file and nothing else, whoops.
    
    Committed only the topfile.
    
    Reopens: #6750
    
    
    git-svn-id: svn://svn.twistedmatrix.com/svn/Twisted/trunk@42757 bbbe8e31-12d6-0310-92fd-ac37d47ddeeb

and

commit 01b4faf9bf570b8c1904c3fc79e557def6bb7c13
Author: wsanchez <wsanchez@bbbe8e31-12d6-0310-92fd-ac37d47ddeeb>
Date:   Tue Jun 3 05:05:13 2014 +0000

    Merge log-booyah-6750-4: Brief description
    
    Author: wsanchez, glyph
    Reviewer: ralphm
    Fixes: #6750
    
    New logging system.
    
    
    git-svn-id: svn://svn.twistedmatrix.com/svn/Twisted/trunk@42756 bbbe8e31-12d6-0310-92fd-ac37d47ddeeb

So, closing this one then.

comment:4 Changed 2 years ago by James

Sorry to resurrect an old issue.

We have an issue in production code with the same stack trace as this ticket.

For us, it occurs only in load situation, so we are looking through our code to understand if we are doing anything wrong. We do not yet have a reliable way to reproduce the issue.

However, we have found that the major releases all have the problem described here when the script attached is run. The fix described here seems to have been backed out.

Could anyone comment if the script shows a real problem or improper usage. (If it's real, I think the ticket should be re-opened).

Note: See TracTickets for help on using tickets.