Record backout seconds instead of call counts

This commit is contained in:
Adrián Chaves 2024-07-09 14:04:16 +02:00
parent 3c5acd252f
commit 36cf156500
3 changed files with 35 additions and 41 deletions

View File

@ -134,6 +134,7 @@ class Downloader:
"DOWNLOAD_SLOTS", {}
)
self._stats = crawler.stats
self._last_backout = (None, None)
deprecated_setting_priority = self.settings.getpriority(
"SCRAPER_SLOT_MAX_ACTIVE_SIZE"
@ -172,13 +173,22 @@ class Downloader:
)
return dfd.addBoth(_deactivate)
def _count_backout(self, reason):
self._stats.inc_value("request_backouts/total")
self._stats.inc_value(f"request_backouts/{reason}")
def _record_backout(self, reason):
last_reason, last_reason_start_time = self._last_backout
if last_reason == reason:
return
current_time = time()
if last_reason is not None:
last_reason_seconds = current_time - last_reason_start_time
self._stats.inc_value("request_backout_seconds/total", last_reason_seconds)
self._stats.inc_value(
f"request_backout_seconds/{last_reason}", last_reason_seconds
)
self._last_backout = (reason, current_time)
def needs_backout(self) -> bool:
if len(self.active) >= self.total_concurrency:
self._count_backout("concurrency")
self._record_backout("concurrency")
return True
if (
self._response_max_active_size
@ -207,11 +217,12 @@ class Downloader:
f"during a crawl for this reason, see the "
f"request_backouts/response_max_active_size stat."
)
self._count_backout("response_max_active_size")
self._record_backout("response_max_active_size")
# Force the garbage collection of response objects. Necessary for
# PyPy, which is lazier when it comes to garbage collection.
gc.collect()
return True
self._record_backout(None)
return False
def _get_slot(self, request: Request, spider: Spider) -> Tuple[str, Slot]:

View File

@ -47,14 +47,6 @@ class CoreStats:
)
self.stats.set_value("finish_time", finish_time, spider=spider)
self.stats.set_value("finish_reason", reason, spider=spider)
if elapsed_time_seconds > 0:
request_backouts = self.stats.get_value("request_backouts/total", 0)
if request_backouts:
self.stats.set_value(
"request_backouts/total_per_second",
request_backouts / elapsed_time_seconds,
spider=spider,
)
def item_scraped(self, item: Any, spider: Spider) -> None:
self.stats.inc_value("item_scraped_count", spider=spider)

View File

@ -195,7 +195,7 @@ class RequestBackoutTest(unittest.TestCase):
stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(stats, {})
@ -241,14 +241,13 @@ class RequestBackoutTest(unittest.TestCase):
self.assertEqual(matching_log_count, 0)
expected_stats = {
"request_backouts/concurrency": gt(0),
"request_backouts/total": gt(0),
"request_backouts/total_per_second": gt(0),
"request_backout_seconds/concurrency": gt(0),
"request_backout_seconds/total": gt(0),
}
actual_stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(expected_stats, actual_stats)
@ -280,17 +279,13 @@ class RequestBackoutTest(unittest.TestCase):
self.assertEqual(matching_log_count, 1)
expected_stats = {
# Test > 1, if 1 then we are not really making sure that the INFO
# message above is logged only once in a scenario where active size
# is checked more than once.
"request_backouts/response_max_active_size": gt(1),
"request_backouts/total": gt(0),
"request_backouts/total_per_second": gt(0),
"request_backout_seconds/response_max_active_size": gt(0),
"request_backout_seconds/total": gt(0),
}
actual_stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(expected_stats, actual_stats)
@ -328,14 +323,13 @@ class RequestBackoutTest(unittest.TestCase):
self.assertEqual(matching_log_count, 1)
expected_stats = {
"request_backouts/response_max_active_size": gt(0),
"request_backouts/total": gt(0),
"request_backouts/total_per_second": gt(0),
"request_backout_seconds/response_max_active_size": gt(0),
"request_backout_seconds/total": gt(0),
}
actual_stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(expected_stats, actual_stats)
@ -373,14 +367,13 @@ class RequestBackoutTest(unittest.TestCase):
self.assertEqual(matching_log_count, 1)
expected_stats = {
"request_backouts/response_max_active_size": gt(0),
"request_backouts/total": gt(0),
"request_backouts/total_per_second": gt(0),
"request_backout_seconds/response_max_active_size": gt(0),
"request_backout_seconds/total": gt(0),
}
actual_stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(expected_stats, actual_stats)
@ -426,14 +419,13 @@ class RequestBackoutTest(unittest.TestCase):
self.assertEqual(matching_log_count, 1)
expected_stats = {
"request_backouts/response_max_active_size": gt(0),
"request_backouts/total": gt(0),
"request_backouts/total_per_second": gt(0),
"request_backout_seconds/response_max_active_size": gt(0),
"request_backout_seconds/total": gt(0),
}
actual_stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(expected_stats, actual_stats)
@ -481,13 +473,12 @@ class RequestBackoutTest(unittest.TestCase):
self.assertEqual(matching_log_count, 1)
expected_stats = {
"request_backouts/response_max_active_size": gt(0),
"request_backouts/total": gt(0),
"request_backouts/total_per_second": gt(0),
"request_backout_seconds/response_max_active_size": gt(0),
"request_backout_seconds/total": gt(0),
}
actual_stats = {
k: v
for k, v in crawler.stats.get_stats().items()
if k.startswith("request_backouts/")
if k.startswith("request_backout_seconds/")
}
self.assertEqual(expected_stats, actual_stats)