emit debug logging messages before calling time.sleep() (#2982)

gallery_dl/extractor/common.py

@@ -122,8 +122,7 @@ class Extractor():
             seconds = (self._interval() -
                        (time.time() - Extractor.request_timestamp))
             if seconds > 0.0:
-                self.log.debug("Sleeping for %.5s seconds", seconds)
-                time.sleep(seconds)
+                self.sleep(seconds, "request")
 
         while True:
             try:
@@ -169,8 +168,9 @@ class Extractor():
             self.log.debug("%s (%s/%s)", msg, tries, retries+1)
             if tries > retries:
                 break
-            time.sleep(
-                max(tries, self._interval()) if self._interval else tries)
+            self.sleep(
+                max(tries, self._interval()) if self._interval else tries,
+                "retry")
             tries += 1
 
         raise exception.HttpError(msg, response)
@@ -202,6 +202,11 @@ class Extractor():
             self.log.info("Waiting until %s for %s.", isotime, reason)
         time.sleep(seconds)
 
+    def sleep(self, seconds, reason):
+        self.log.debug("Sleeping %.2f seconds (%s)",
+                       seconds, reason)
+        time.sleep(seconds)
+
     def _get_auth_info(self):
         """Return authentication information as (username, password) tuple"""
         username = self.config("username")

gallery_dl/job.py

@@ -8,7 +8,6 @@
 
 import sys
 import json
-import time
 import errno
 import logging
 import functools
@@ -74,9 +73,10 @@ class Job():
         log = extractor.log
         msg = None
 
-        sleep = util.build_duration_func(extractor.config("sleep-extractor"))
+        sleep = util.build_duration_func(
+            extractor.config("sleep-extractor"))
         if sleep:
-            time.sleep(sleep())
+            extractor.sleep(sleep(), "extractor")
 
         try:
             for msg in extractor:
@@ -238,7 +238,7 @@ class DownloadJob(Job):
             return
 
         if self.sleep:
-            time.sleep(self.sleep())
+            self.extractor.sleep(self.sleep(), "download")
 
         # download from URL
         if not self.download(url):
@@ -527,11 +527,11 @@ class SimulationJob(DownloadJob):
         if not kwdict["extension"]:
             kwdict["extension"] = "jpg"
         self.pathfmt.set_filename(kwdict)
-        self.out.skip(self.pathfmt.path)
         if self.sleep:
-            time.sleep(self.sleep())
+            self.extractor.sleep(self.sleep(), "download")
         if self.archive:
             self.archive.add(kwdict)
+        self.out.skip(self.pathfmt.path)
 
     def handle_directory(self, kwdict):
         if not self.pathfmt:
@@ -700,14 +700,15 @@ class DataJob(Job):
         self.filter = util.identity if private else util.filter_dict
 
     def run(self):
+        extractor = self.extractor
         sleep = util.build_duration_func(
-            self.extractor.config("sleep-extractor"))
+            extractor.config("sleep-extractor"))
         if sleep:
-            time.sleep(sleep())
+            extractor.sleep(sleep(), "extractor")
 
         # collect data
         try:
-            for msg in self.extractor:
+            for msg in extractor:
                 self.dispatch(msg)
         except exception.StopExtraction:
             pass