pytest-dev / pytest-dev/pytest
Caplog don't capture all logs
Nobody has claimed this yet.
- Dominant language
- Python
- Stars
- 14.5k
- Forks
- 3.4k
- Avg merge
- 2d 9h
- Merged PRs (30d)
- 35
Description
Caplog start capturing, but in a specific place capturing is stopped.
It reproduces in one test and does not reproduce in the rest.
Additional I need caplog.set_level('DEBUG') for this test (specify the logging level for caplog, otherwise nothing gets into it at all). In another tests this not need.
Example of output:
root@b1ad842cef21:/usr/src/app# pytest ./tests/functional/test_scraping_wix_site.py -s
/usr/local/lib/python3.7/site-packages/twisted/internet/address.py:101: DeprecationWarning: The usage of `cmp` is deprecated and will be removed on or after 2021-06-01. Please use `eq` and `order` instead.
@attr.s(hash=False, repr=False, cmp=False)
====================================================================== test session starts ======================================================================
platform linux -- Python 3.7.3, pytest-5.3.5, py-1.8.1, pluggy-0.13.1
rootdir: /usr/src/app, inifile: pytest.ini
plugins: twisted-1.12, cov-2.8.1
collected 1 item
tests/functional/test_scraping_wix_site.py ---- init logging
2020-06-08 04:43:55,519 - botocore.hooks - DEBUG - Changing event name from creating-client-class.iot-data to creating-client-class.iot-data-plane
2020-06-08 04:43:55,526 - botocore.hooks - DEBUG - Changing event name from before-call.apigateway to before-call.api-gateway
<... some logs ...>
2020-06-08 04:43:55,740 - scrapy.middleware - INFO - Enabled item pipelines:
['crawler.pipelines.MysqlPipeline', 'crawler.pipelines.ScreenshotPipeline']
2020-06-08 04:43:55,740 - scrapy.core.engine - INFO - Spider opened
2020-06-08 04:43:55,760 - scrapy.extensions.logstats - INFO - Crawled 0 pages (at 0 pages/min), scraped 0 items (at 0 items/min)
2020-06-08 04:43:56,447 - urllib3.connectionpool - DEBUG - Starting new HTTP connection (1): splash:8050
2020-06-08 04:43:56,640 - urllib3.connectionpool - DEBUG - http://splash:8050 "POST /_gc HTTP/1.1" 200 72
2020-06-08 04:43:56,666 - urllib3.connectionpool - DEBUG - Starting new HTTP connection (1): splash:8050
<... some logs ...>
2020-06-08 04:44:28,617 - scrapy.statscollectors - INFO - Dumping Scrapy stats:
{'crawler_error_code': 5,
'downloader/request_bytes': 4233,
'downloader/request_count': 6,
'downloader/request_method_count/POST': 6,
'downloader/response_bytes': 1219766,
'downloader/response_count': 6,
'downloader/response_status_count/200': 6,
'elapsed_time_seconds': 32.852748,
'finish_reason': 'expected_crawler_error',
'finish_time': datetime.datetime(2020, 6, 8, 4, 44, 28, 614023),
'item_scraped_count': 4,
'log_count/INFO': 4,
'memusage/max': 148881408,
'memusage/startup': 148881408,
'parse_start_url': 'https://www.webseowriter.net',
'pipeline_mysql/external_links_saved': 0,
'pipeline_mysql/images_saved': 0,
'pipeline_mysql/pages_saved': 1,
'pipeline_mysql/url_links_saved': 0,
'pipeline_screenshot/screenshots_failure': 0,
'request_depth_count/0': 1,
'request_depth_count/1': 1,
'request_depth_max': 1,
'response_received_count': 3,
'robotstxt/request_count': 1,
'robotstxt/response_count': 1,
'robotstxt/response_status_count/200': 1,
'scheduler/dequeued': 6,
'scheduler/dequeued/memory': 6,
'scheduler/enqueued': 6,
'scheduler/enqueued/memory': 6,
'splash/render.html/request_count': 3,
'splash/render.html/response_count/200': 3,
'splash/render.png/request_count': 3,
'splash/render.png/response_count/200': 3,
'start_time': datetime.datetime(2020, 6, 8, 4, 43, 55, 761275)}
2020-06-08 04:44:28,618 - scrapy.core.engine - INFO - Spider closed (expected_crawler_error)
F
=========================================================================== FAILURES ============================================================================
In caplog.text:
INFO scrapy.crawler:crawler.py:49 Overridden settings: {'AJAXCRAWL_ENABLED': True, 'BOT_NAME': 'crawler', 'CONCURRENT_ITEMS': 500, 'CONCURRENT_REQUESTS': 100, 'CONCURRENT_REQUESTS_PER_DOMAIN': 500, 'COOKIES_ENABLED': False, 'DEPTH_LIMIT': 20, 'DEPTH_PRIORITY': 1, 'DEPTH_STATS_VERBOSE': True, 'DOWNLOAD_DELAY': 0.1, 'DOWNLOAD_MAXSIZE': 2097152, 'DOWNLOAD_TIMEOUT': 50, 'FILES_STORE_S3_ACL': 'public-read', 'HTTPCACHE_POLICY': 'scrapy.extensions.httpcache.RFC2616Policy', 'HTTPCACHE_STORAGE': 'scrapy.extensions.httpcache.DbmCacheStorage', 'NEWSPIDER_MODULE': 'crawler.spiders', 'REACTOR_THREADPOOL_MAXSIZE': 50, 'REDIRECT_MAX_TIMES': 10, 'RETRY_ENABLED': False, 'ROBOTSTXT_OBEY': True, 'SPIDER_MODULES': ['crawler.spiders'], 'TELNETCONSOLE_ENABLED': False, 'USER_AGENT': 'Mozilla/5.0 (Windows NT 10.0 Win64x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.77 Safari/537.36'}
INFO scrapy.middleware:middleware.py:48 Enabled extensions:
['scrapy.extensions.memusage.MemoryUsage',
'scrapy.extensions.logstats.LogStats',
'scrapy.extensions.corestats.CoreStats',
'crawler.extentions.SpiderDetectJS']
INFO scrapy.middleware:middleware.py:48 Enabled downloader middlewares:
['scrapy.spidermiddlewares.depth.DepthMiddleware',
'scrapy.downloadermiddlewares.httpauth.HttpAuthMiddleware',
'scrapy.downloadermiddlewares.downloadtimeout.DownloadTimeoutMiddleware',
'scrapy.downloadermiddlewares.defaultheaders.DefaultHeadersMiddleware',
'scrapy.downloadermiddlewares.useragent.UserAgentMiddleware',
'scrapy.downloadermiddlewares.ajaxcrawl.AjaxCrawlMiddleware',
'scrapy.downloadermiddlewares.redirect.MetaRefreshMiddleware',
'crawler.middlewares.CrawlerDownloaderWixMiddleware',
'rotating_proxies.middlewares.BanDetectionMiddleware',
'crawler.middlewares.CrawlerDownloaderMiddleware',
'scrapy_splash.SplashCookiesMiddleware',
'scrapy_splash.SplashMiddleware',
'scrapy.downloadermiddlewares.httpproxy.HttpProxyMiddleware',
'scrapy.downloadermiddlewares.httpcompression.HttpCompressionMiddleware',
'scrapy.downloadermiddlewares.stats.DownloaderStats']
INFO scrapy.middleware:middleware.py:48 Enabled spider middlewares:
['scrapy.spidermiddlewares.httperror.HttpErrorMiddleware',
'scrapy_splash.SplashDeduplicateArgsMiddleware',
'scrapy.spidermiddlewares.offsite.OffsiteMiddleware',
'crawler.middlewares.CrawlerSpiderMiddleware',
'scrapy.spidermiddlewares.referer.RefererMiddleware',
'scrapy.spidermiddlewares.urllength.UrlLengthMiddleware',
'scrapy.spidermiddlewares.depth.DepthMiddleware']
Additional Info
root@b1ad842cef21:/usr/src/app# pip list
Package Version
----------------------- ----------
attrs 19.3.0
Automat 20.2.0
beautifulsoup4 4.8.2
boto3 1.12.4
botocore 1.15.49
certifi 2020.4.5.1
cffi 1.14.0
chardet 3.0.4
click 7.1.2
click-log 0.3.2
constantly 15.1.0
coverage 5.1
cryptography 2.9.2
cssselect 1.1.0
decorator 4.4.2
detectem 0.7.1
docker 4.1.0
docutils 0.15.2
greenlet 0.4.15
hyperlink 19.0.0
idna 2.8
importlib-metadata 1.6.0
incremental 17.5.0
jmespath 0.10.0
logstash-formatter 0.5.17
lxml 4.5.1
more-itertools 8.3.0
mysqlclient 1.4.6
packaging 20.4
pact-python 0.21.0
parsel 1.6.0
pip 19.1.1
pluggy 0.13.1
Protego 0.1.16
psutil 5.7.0
py 1.8.1
pyasn1 0.4.8
pyasn1-modules 0.2.8
pycparser 2.20
PyDispatcher 2.0.5
PyHamcrest 2.0.2
pyOpenSSL 19.1.0
pyparsing 2.4.7
pytest 5.3.5
pytest-cov 2.8.1
pytest-twisted 1.12
python-dateutil 2.8.1
python3-logstash 0.4.80
queuelib 1.5.0
requests 2.22.0
requests-file 1.5.1
responses 0.10.9
s3transfer 0.3.3
scrapoxy 1.11
Scrapy 1.8.0
scrapy-rotating-proxies 0.6.2
scrapy-splash 0.7.2
service-identity 18.1.0
setuptools 41.0.1
simplejson 3.17.0
six 1.15.0
soupsieve 2.0.1
SQLAlchemy 1.3.13
tldextract 2.2.2
Twisted 19.10.0
typing 3.7.4.1
urllib3 1.25.9
w3lib 1.21.0
wcwidth 0.1.9
websocket-client 0.57.0
wheel 0.33.1
zipp 3.1.0
zope.interface 5.1.0
WARNING: You are using pip version 19.1.1, however version 20.1.1 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
root@b1ad842cef21:/usr/src/app# pytest --version
This is pytest version 5.3.5, imported from /usr/local/lib/python3.7/site-packages/pytest/__init__.py
setuptools registered plugins:
pytest-twisted-1.12 at /usr/local/lib/python3.7/site-packages/pytest_twisted.py
pytest-cov-2.8.1 at /usr/local/lib/python3.7/site-packages/pytest_cov/plugin.py
root@b1ad842cef21:/usr/src/app# uname -a
Linux b1ad842cef21 5.3.0-46-generic #38~18.04.1-Ubuntu SMP Tue Mar 31 04:17:56 UTC 2020 x86_64 GNU/Linux
Reproduce
I will try to prepare the minimum code a bit later
- a detailed description of the bug or suggestion
- output of
pip listfrom the virtual environment you are using - pytest and operating system versions
- minimal example if possible
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by running pytest ./tests/functional/test_scraping_wix_site.py -s and inspect the caplog usage in that test, including caplog.set_level('DEBUG'). Compare the terminal output with caplog.text to identify where capture stops. Done means a minimal reproduction is available and the missing logs are captured consistently with a regression test.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- testing-qa
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100