Repository: scrapy/scrapy
Pull request: Spider middleware: catch spider callback exceptions early
Fixes #4260.

Evaluates the output iterable right after the spider callback, as it's currently being done in the `process_spider_output` chain.

(Plus some minor styling adjustments)

Problem statement:
First Spider Middleware does not process exception for generator callback
### Description

`process_spider_exception` method of a spider middleware is ignored when spider middleware is first and callback is a generator.

### Steps to Reproduce

1. Create spider middleware with defined `process_spider_exception`
2. Put it into `SPIDER_MIDDLEWARES` with number more than `900` (to make it first)
3. Raise an exception in a spider callback
4. UPD. Yield an item from the callback

**Expected behavior:** `process_spider_exception` is called for this exception

**Actual behavior:** `process_spider_exception` is not called

### Versions

```
Scrapy       : 1.7.1
lxml         : 4.2.5.0
libxml2      : 2.9.8
cssselect    : 1.0.3
parsel       : 1.5.1
w3lib        : 1.19.0
Twisted      : 18.9.0
Python       : 3.6.8 (default, May  8 2019, 05:35:00) - [GCC 6.3.0 20170516]
pyOpenSSL    : 18.0.0 (OpenSSL 1.1.0j  20 Nov 2018)
cryptography : 2.4.2
Platform     : Linux-4.9.184-linuxkit-x86_64-with-debian-9.9
```

Hints from issue discussion:
Could you provide some code and logs? I could not reproduce the issue, either with `1.7.1` (your version) or with `1.8.0` (latest version). I assigned both `1` and `901` to the middleware, and the exception is caught regardless (please see [the diagram in this comment](https://github.com/scrapy/scrapy/pull/2061#issuecomment-406371658), the last `process_spider_exception` method to be executed is the one from the middleware with the lowest number).

```python
import scrapy


class ExceptionHandlerMiddleware:
    def process_spider_exception(self, response, exception, spider):
        print('Exception caught:', exception)
        return []


class ExceptionSpider(scrapy.Spider):
    name = 'exception_spider'
    start_urls = ['https://example.org']
    custom_settings = {
        'SPIDER_MIDDLEWARES': {
            __name__ + '.ExceptionHandlerMiddleware': 1,
        }
    }

    def parse(self, response):
        raise Exception('foo')
```

```
$ scrapy runspider lastmw.py
(...)
2019-12-31 01:32:25 [scrapy.core.engine] INFO: Spider opened
2019-12-31 01:32:25 [scrapy.extensions.logstats] INFO: Crawled 0 pages (at 0 pages/min), scraped 0 items (at 0 items/min)
2019-12-31 01:32:25 [scrapy.extensions.telnet] INFO: Telnet console listening on 127.0.0.1:6023
2019-12-31 01:32:25 [scrapy.core.engine] DEBUG: Crawled (200) <GET https://example.org> (referer: None)
Exception caught: foo
2019-12-31 01:32:25 [scrapy.core.engine] INFO: Closing spider (finished)
(...)
```

```
$ scrapy version --verbose
Scrapy       : 1.7.1
lxml         : 4.2.6.0
libxml2      : 2.9.9
cssselect    : 1.0.3
parsel       : 1.5.1
w3lib        : 1.19.0
Twisted      : 18.9.0
Python       : 3.6.6 (v3.6.6:4cf1f54eb7, Jun 26 2018, 19:50:54) - [GCC 4.2.1 Compatible Apple LLVM 6.0 (clang-600.0.57)]
pyOpenSSL    : 18.0.0 (OpenSSL 1.1.0i  14 Aug 2018)
cryptography : 2.3.1
Platform     : Darwin-18.7.0-x86_64-i386-64bit
```

```
$ scrapy version --verbose
Scrapy       : 1.8.0
lxml         : 4.2.6.0
libxml2      : 2.9.9
cssselect    : 1.0.3
parsel       : 1.5.1
w3lib        : 1.19.0
Twisted      : 18.9.0
Python       : 3.6.6 (v3.6.6:4cf1f54eb7, Jun 26 2018, 19:50:54) - [GCC 4.2.1 Compatible Apple LLVM 6.0 (clang-600.0.57)]
pyOpenSSL    : 18.0.0 (OpenSSL 1.1.0i  14 Aug 2018)
cryptography : 2.3.1
Platform     : Darwin-18.7.0-x86_64-i386-64bit
```



If you add `yield {}` to the callback (doesn't matter before or after the exception), it won't be caught.
It is caught however when the number of middleware is not the highest one (e.g. 899 works, but 901 does not).
Ok, that changes things. Indeed, I this is what I'm getting:

```python
import scrapy


class ExceptionHandlerMiddleware:
    def process_spider_exception(self, response, exception, spider):
        print('Exception caught:', exception)
        return []


class ExceptionSpider(scrapy.Spider):
    name = 'exception_spider'
    start_urls = ['https://example.org']
    custom_settings = {
        'SPIDER_MIDDLEWARES': {
            __name__ + '.ExceptionHandlerMiddleware': 901,
        }
    }

    def parse(self, response):
        yield
        raise Exception('foo')
```

```
$ scrapy runspider lastmw.py
(...)
2020-01-03 12:21:09 [scrapy.core.engine] INFO: Spider opened
2020-01-03 12:21:09 [scrapy.extensions.logstats] INFO: Crawled 0 pages (at 0 pages/min), scraped 0 items (at 0 items/min)
2020-01-03 12:21:09 [scrapy.extensions.telnet] INFO: Telnet console listening on 127.0.0.1:6023
2020-01-03 12:21:10 [scrapy.core.engine] DEBUG: Crawled (200) <GET https://example.org> (referer: None)
2020-01-03 12:21:10 [scrapy.core.scraper] ERROR: Spider error processing <GET https://example.org> (referer: None)
Traceback (most recent call last):
  File "/.../scrapy/scrapy/utils/defer.py", line 102, in iter_errback
    yield next(it)
  File "/.../scrapy/scrapy/core/spidermw.py", line 84, in evaluate_iterable
    for r in iterable:
  File "/.../scrapy/scrapy/spidermiddlewares/offsite.py", line 29, in process_spider_output
    for x in result:
  File "/.../scrapy/scrapy/core/spidermw.py", line 84, in evaluate_iterable
    for r in iterable:
  File "/.../scrapy/scrapy/spidermiddlewares/referer.py", line 339, in <genexpr>
    return (_set_referer(r) for r in result or ())
  File "/.../scrapy/scrapy/core/spidermw.py", line 84, in evaluate_iterable
    for r in iterable:
  File "/.../scrapy/scrapy/spidermiddlewares/urllength.py", line 37, in <genexpr>
    return (r for r in result or () if _filter(r))
  File "/.../scrapy/scrapy/core/spidermw.py", line 84, in evaluate_iterable
    for r in iterable:
  File "/.../scrapy/scrapy/spidermiddlewares/depth.py", line 58, in <genexpr>
    return (r for r in result or () if _filter(r))
  File "/.../lastmw.py", line 21, in parse
    raise Exception('foo')
Exception: foo
2020-01-03 12:21:10 [scrapy.core.engine] INFO: Closing spider (finished)
(...)
```
It seems to me like this is an edge case of #220. By the time the middleware that's closest to the spider is executed the iterable from the spider callback has not been evaluated yet. The exception is raised in the first `process_spider_output` method but the execution chain jumps from one middleware to the next one (the _previous_ one in numerical order), so the `process_spider_exception` method is not invoked.
I can think of two workarounds while this issue is still present:
1. Do not assign the highest priority to the middleware in question
2. Put a dummy middleware right in between the spider and the middleware manager:

```python
import scrapy


class ExceptionHandlerMiddleware:
    def process_spider_exception(self, response, exception, spider):
        print('Exception caught:', exception)
        return []


class DummyMiddleware:
    def process_spider_output(self, response, result, spider):
        yield from result


class ExceptionSpider(scrapy.Spider):
    name = 'exception_spider'
    start_urls = ['https://example.org']
    custom_settings = {
        'SPIDER_MIDDLEWARES': {
            __name__ + '.DummyMiddleware': 902,
            __name__ + '.ExceptionHandlerMiddleware': 901,
        }
    }

    def parse(self, response):
        yield
        raise Exception('foo')

```

Commit message: Spider middleware: simplify deferred errback handling

Patch to review:
diff --git a/scrapy/core/spidermw.py b/scrapy/core/spidermw.py
index 097a374bfaa..ed02b306baa 100644
--- a/scrapy/core/spidermw.py
+++ b/scrapy/core/spidermw.py
@@ -3,13 +3,14 @@
 
 See documentation in docs/topics/spider-middleware.rst
 """
-from itertools import chain, islice
+from itertools import islice
 
 from twisted.python.failure import Failure
+
 from scrapy.exceptions import _InvalidOutput
 from scrapy.middleware import MiddlewareManager
-from scrapy.utils.defer import mustbe_deferred
 from scrapy.utils.conf import build_component_list
+from scrapy.utils.defer import mustbe_deferred
 from scrapy.utils.python import MutableChain
 
 
@@ -17,6 +18,13 @@ def _isiterable(possible_iterator):
     return hasattr(possible_iterator, '__iter__')
 
 
+def _fname(f):
+    return "%s.%s".format(
+        f.__self__.__class__.__name__,
+        f.__func__.__name__
+    )
+
+
 class SpiderMiddlewareManager(MiddlewareManager):
 
     component_name = 'spider middleware'
@@ -31,27 +39,36 @@ def _add_middleware(self, mw):
             self.methods['process_spider_input'].append(mw.process_spider_input)
         if hasattr(mw, 'process_start_requests'):
             self.methods['process_start_requests'].appendleft(mw.process_start_requests)
-        self.methods['process_spider_output'].appendleft(getattr(mw, 'process_spider_output', None))
-        self.methods['process_spider_exception'].appendleft(getattr(mw, 'process_spider_exception', None))
+        process_spider_output = getattr(mw, 'process_spider_output', None)
+        self.methods['process_spider_output'].appendleft(process_spider_output)
+        process_spider_exception = getattr(mw, 'process_spider_exception', None)
+        self.methods['process_spider_exception'].appendleft(process_spider_exception)
 
     def scrape_response(self, scrape_func, response, request, spider):
-        fname = lambda f: '%s.%s' % (
-                f.__self__.__class__.__name__,
-                f.__func__.__name__)
 
         def process_spider_input(response):
             for method in self.methods['process_spider_input']:
                 try:
                     result = method(response=response, spider=spider)
                     if result is not None:
-                        raise _InvalidOutput('Middleware {} must return None or raise an exception, got {}'
-                                             .format(fname(method), type(result)))
+                        msg = "Middleware {} must return None or raise an exception, got {}"
+                        raise _InvalidOutput(msg.format(_fname(method), type(result)))
                 except _InvalidOutput:
                     raise
                 except Exception:
                     return scrape_func(Failure(), request, spider)
             return scrape_func(response, request, spider)
 
+        def _evaluate_iterable(iterable, method_index, recover_to):
+            try:
+                for r in iterable:
+                    yield r
+            except Exception as ex:
+                exception_result = process_spider_exception(Failure(ex), method_index)
+                if isinstance(exception_result, Failure):
+                    raise
+                recover_to.extend(exception_result)
+
         def process_spider_exception(_failure, start_index=0):
             exception = _failure.value
             # don't handle _InvalidOutput exception
@@ -69,8 +86,8 @@ def process_spider_exception(_failure, start_index=0):
                 elif result is None:
                     continue
                 else:
-                    raise _InvalidOutput('Middleware {} must return None or an iterable, got {}'
-                                         .format(fname(method), type(result)))
+                    msg = "Middleware {} must return None or an iterable, got {}"
+                    raise _InvalidOutput(msg.format(_fname(method), type(result)))
             return _failure
 
         def process_spider_output(result, start_index=0):
@@ -78,38 +95,34 @@ def process_spider_output(result, start_index=0):
             # chain, they went through it already from the process_spider_exception method
             recovered = MutableChain()
 
-            def evaluate_iterable(iterable, index):
-                try:
-                    for r in iterable:
-                        yield r
-                except Exception as ex:
-                    exception_result = process_spider_exception(Failure(ex), index+1)
-                    if isinstance(exception_result, Failure):
-                        raise
-                    recovered.extend(exception_result)
-
             method_list = islice(self.methods['process_spider_output'], start_index, None)
             for method_index, method in enumerate(method_list, start=start_index):
                 if method is None:
                     continue
-                # the following might fail directly if the output value is not a generator
                 try:
+                    # might fail directly if the output value is not a generator
                     result = method(response=response, result=result, spider=spider)
                 except Exception as ex:
                     exception_result = process_spider_exception(Failure(ex), method_index+1)
                     if isinstance(exception_result, Failure):
                         raise
                     return exception_result
-                if _isiterable(result):
-                    result = evaluate_iterable(result, method_index)
                 else:
-                    raise _InvalidOutput('Middleware {} must return an iterable, got {}'
-                                         .format(fname(method), type(result)))
+                    if _isiterable(result):
+                        result = _evaluate_iterable(result, method_index+1, recovered)
+                    else:
+                        msg = "Middleware {} must return an iterable, got {}"
+                        raise _InvalidOutput(msg.format(_fname(method), type(result)))
+
+            return MutableChain(result, recovered)
 
-            return chain(result, recovered)
+        def process_callback_output(result):
+            recovered = MutableChain()
+            result = _evaluate_iterable(result, 0, recovered)
+            return MutableChain(process_spider_output(result), recovered)
 
         dfd = mustbe_deferred(process_spider_input, response)
-        dfd.addCallbacks(callback=process_spider_output, errback=process_spider_exception)
+        dfd.addCallbacks(callback=process_callback_output, errback=process_spider_exception)
         return dfd
 
     def process_start_requests(self, start_requests, spider):
diff --git a/scrapy/utils/python.py b/scrapy/utils/python.py
index 8d829c5a5df..e5582cc18cb 100644
--- a/scrapy/utils/python.py
+++ b/scrapy/utils/python.py
@@ -1,15 +1,15 @@
 """
 This module contains essential stuff that should've come with Python itself ;)
 """
+import errno
 import gc
+import inspect
 import os
 import re
-import inspect
+import sys
 import weakref
-import errno
 from functools import partial, wraps
 from itertools import chain
-import sys
 
 from scrapy.utils.decorators import deprecated
 
@@ -371,10 +371,11 @@ def garbage_collect():
         gc.collect()
 
 
-class MutableChain(object):
+class MutableChain:
     """
     Thin wrapper around itertools.chain, allowing to add iterables "in-place"
     """
+
     def __init__(self, *args):
         self.data = chain(*args)
 
diff --git a/tests/test_spidermiddleware_output_chain.py b/tests/test_spidermiddleware_output_chain.py
index 739cf1c2d62..b19a74609e4 100644
--- a/tests/test_spidermiddleware_output_chain.py
+++ b/tests/test_spidermiddleware_output_chain.py
@@ -1,10 +1,10 @@
-
 from testfixtures import LogCapture
-from twisted.trial.unittest import TestCase
 from twisted.internet import defer
+from twisted.trial.unittest import TestCase
 
-from scrapy import Spider, Request
+from scrapy import Request, Spider
 from scrapy.utils.test import get_crawler
+
 from tests.mockserver import MockServer
 
 
@@ -74,7 +74,7 @@ class ProcessSpiderInputSpiderWithErrback(ProcessSpiderInputSpiderWithoutErrback
     name = 'ProcessSpiderInputSpiderWithErrback'
 
     def start_requests(self):
-        yield Request(url=self.mockserver.url('/status?n=200'), callback=self.parse, errback=self.errback)
+        yield Request(self.mockserver.url('/status?n=200'), self.parse, errback=self.errback)
 
     def errback(self, failure):
         self.logger.info('Got a Failure on the Request errback')
@@ -100,6 +100,17 @@ def parse(self, response):
         raise ImportError()
 
 
+# ================================================================================
+# (2.1) exceptions from a spider callback (generator, middleware right after callback)
+class GeneratorCallbackSpiderMiddlewareRightAfterSpider(GeneratorCallbackSpider):
+    name = 'GeneratorCallbackSpiderMiddlewareRightAfterSpider'
+    custom_settings = {
+        'SPIDER_MIDDLEWARES': {
+            __name__ + '.LogExceptionMiddleware': 100000,
+        },
+    }
+
+
 # ================================================================================
 # (3) exceptions from a spider callback (not a generator)
 class NotGeneratorCallbackSpider(Spider):
@@ -117,6 +128,17 @@ def parse(self, response):
         return [{'test': 1}, {'test': 1/0}]
 
 
+# ================================================================================
+# (3.1) exceptions from a spider callback (not a generator, middleware right after callback)
+class NotGeneratorCallbackSpiderMiddlewareRightAfterSpider(NotGeneratorCallbackSpider):
+    name = 'NotGeneratorCallbackSpiderMiddlewareRightAfterSpider'
+    custom_settings = {
+        'SPIDER_MIDDLEWARES': {
+            __name__ + '.LogExceptionMiddleware': 100000,
+        },
+    }
+
+
 # ================================================================================
 # (4) exceptions from a middleware process_spider_output method (generator)
 class GeneratorOutputChainSpider(Spider):
@@ -320,6 +342,16 @@ def test_generator_callback(self):
         self.assertIn("Middleware: ImportError exception caught", str(log2))
         self.assertIn("'item_scraped_count': 2", str(log2))
 
+    @defer.inlineCallbacks
+    def test_generator_callback_right_after_callback(self):
+        """
+        (2.1) Special case of (2): Exceptions should be caught
+        even if the middleware is placed right after the spider
+        """
+        log21 = yield self.crawl_log(GeneratorCallbackSpiderMiddlewareRightAfterSpider)
+        self.assertIn("Middleware: ImportError exception caught", str(log21))
+        self.assertIn("'item_scraped_count': 2", str(log21))
+
     @defer.inlineCallbacks
     def test_not_a_generator_callback(self):
         """
@@ -330,6 +362,16 @@ def test_not_a_generator_callback(self):
         self.assertIn("Middleware: ZeroDivisionError exception caught", str(log3))
         self.assertNotIn("item_scraped_count", str(log3))
 
+    @defer.inlineCallbacks
+    def test_not_a_generator_callback_right_after_callback(self):
+        """
+        (3.1) Special case of (3): Exceptions should be caught
+        even if the middleware is placed right after the spider
+        """
+        log31 = yield self.crawl_log(NotGeneratorCallbackSpiderMiddlewareRightAfterSpider)
+        self.assertIn("Middleware: ZeroDivisionError exception caught", str(log31))
+        self.assertNotIn("item_scraped_count", str(log31))
+
     @defer.inlineCallbacks
     def test_generator_output_chain(self):
         """


Code review comments:
diff_hunk: @@ -69,47 +86,43 @@ def process_spider_exception(_failure, start_index=0):
                 elif result is None:
                     continue
                 else:
-                    raise _InvalidOutput('Middleware {} must return None or an iterable, got {}'
-                                         .format(fname(method), type(result)))
+                    msg = "Middleware {} must return None or an iterable, got {}"
+                    raise _InvalidOutput(msg.format(_fname(method), type(result)))
             return _failure
 
         def process_spider_output(result, start_index=0):
             # items in this iterable do not need to go through the process_spider_output
             # chain, they went through it already from the process_spider_exception method
             recovered = MutableChain()
 
-            def evaluate_iterable(iterable, index):
-                try:
-                    for r in iterable:
-                        yield r
-                except Exception as ex:
-                    exception_result = process_spider_exception(Failure(ex), index+1)
-                    if isinstance(exception_result, Failure):
-                        raise
-                    recovered.extend(exception_result)
-
             method_list = islice(self.methods['process_spider_output'], start_index, None)
             for method_index, method in enumerate(method_list, start=start_index):
                 if method is None:
                     continue
-                # the following might fail directly if the output value is not a generator
                 try:
+                    # might fail directly if the output value is not a generator
                     result = method(response=response, result=result, spider=spider)
                 except Exception as ex:
                     exception_result = process_spider_exception(Failure(ex), method_index+1)
                     if isinstance(exception_result, Failure):
                         raise
                     return exception_result
-                if _isiterable(result):
-                    result = evaluate_iterable(result, method_index)
                 else:
path: scrapy/core/spidermw.py
text: @user1:
💄 is else needed here?

@author:
Not really, because of the above `return exception_result`. I just thought it would make the separation clearer.

@author:
Removed in ad4477d335bee8b10bc3bbca969defddd9b316f8.
The `else` is still there and the comment does not appear as "outdated" because it's now part of the `if _isiterable(result)` block, not the `try...except` one.