From 1a1df9947c90ca99b099582013dd4fad145adc7e Mon Sep 17 00:00:00 2001 From: cclauss Date: Tue, 14 Apr 2020 13:53:20 +0200 Subject: [PATCH 1/8] lending.py: Add logging to exceptions --- openlibrary/core/lending.py | 37 +++++++++++++++++++++---------------- 1 file changed, 21 insertions(+), 16 deletions(-) diff --git a/openlibrary/core/lending.py b/openlibrary/core/lending.py index 700d311de88..81e24027ec9 100644 --- a/openlibrary/core/lending.py +++ b/openlibrary/core/lending.py @@ -109,6 +109,7 @@ def cached_work_authors_and_subjects(work_id): get_work_authors_and_related_subjects, 'works_authors_and_subjects', timeout=dateutil.HALF_DAY_SECS)(work_id) except AttributeError: + logger.exception("cached_work_authors_and_subjects(%s)" % work_id) return {'authors': [], 'subject': []} @public @@ -187,14 +188,15 @@ def compose_ia_url(limit=None, page=1, subject=None, query=None, work_id=None, def get_random_available_ia_edition(): """uses archive advancedsearch to raise a random book""" try: - url=("http://%s/advancedsearch.php?q=_exists_:openlibrary_work"\ - "+AND+loans__status__status:AVAILABLE"\ - "&fl=identifier,openlibrary_edition,loans__status__status"\ - "&output=json&rows=1&sort[]=random" % (config_bookreader_host)) + url = ("http://%s/advancedsearch.php?q=_exists_:openlibrary_work" + "+AND+loans__status__status:AVAILABLE" + "&fl=identifier,openlibrary_edition,loans__status__status" + "&output=json&rows=1&sort[]=random" % (config_bookreader_host)) content = urllib.request.urlopen(url=url, timeout=config_http_request_timeout).read() items = simplejson.loads(content).get('response', {}).get('docs', []) return items[0]["openlibrary_edition"] - except Exception as e: + except Exception: # TODO: Narrow exception scope + logger.exception("get_random_available_ia_edition(%s)" % url) return None def get_available(limit=None, page=1, subject=None, query=None, @@ -227,7 +229,8 @@ def get_available(limit=None, page=1, subject=None, query=None, results[item['openlibrary_work']] = item['openlibrary_edition'] books = web.ctx.site.get_many(['/books/%s' % result for result in results.values()]) return books - except Exception as e: + except Exception: # TODO: Narrow exception scope + logger.exception("get_available(%s)" % url) return {'error': 'request_timeout'} @@ -241,7 +244,8 @@ def get_availability(key, ids): try: content = urllib.request.urlopen(url=url, timeout=config_http_request_timeout).read() return simplejson.loads(content).get('responses', {}) - except Exception as e: + except Exception as e: # TODO: Narrow exception scope + logger.exception("get_availability(%s)" % url) return {'error': 'request_timeout', 'details': str(e)} def get_edition_availability(ol_edition_id): @@ -343,7 +347,8 @@ def is_loaned_out_on_ia(identifier): try: response = simplejson.loads(urllib.request.urlopen(url).read()) return response and response.get('checkedout') - except: + except Exception: # TODO: Narrow exception scope + logger.exception("is_loaned_out_on_ia(%s)" % identifier) return None @@ -375,13 +380,13 @@ def get_loan(identifier, user_key=None): return loan.delete() try: _loan = _get_ia_loan(identifier, account and userkey2userid(account.username)) - except Exception as e: - pass + except Exception: # TODO: Narrow exception scope + logger.exception("get_loan(%s) 1 of 2" % identifier) try: _loan = _get_ia_loan(identifier, account and account.itemname) - except Exception as e: - pass + except Exception: # TODO: Narrow exception scope + logger.exception("get_loan(%s) 2 of 2" % identifier) return _loan @@ -473,11 +478,11 @@ def sync_loan(identifier, loan=NOT_INITIALIZED): } try: ebook.update(**kwargs) - except Exception: + except Exception: # TODO: Narrow exception scope # updating ebook document is sometimes failing with # "Document update conflict" error. # Log the error in such cases, don't crash. - logger.error("failed to update ebook for %s", identifier, exc_info=True) + logger.exception("failed to update ebook for %s", identifier) # fire loan-completed event if is_loan_completed and ebook.get('loan'): @@ -716,7 +721,7 @@ def get_data(self): try: return simplejson.loads(urllib.request.urlopen(url).read()) except IOError: - logger.error("unable to conact BSS server", exc_info=True) + logger.exception("unable to conact BSS server") def has_loan(self): return bool(self.get_loan()) @@ -805,7 +810,7 @@ def _post(self, **params): timeout=config_http_request_timeout).read() logger.info("POST response: %s", jsontext) return simplejson.loads(jsontext) - except Exception as e: + except Exception: # TODO: Narrow exception scope logger.exception("POST failed") raise From 5a6e3cbaf4c4b1dbca89ca719b21616b4a3e902d Mon Sep 17 00:00:00 2001 From: cclauss Date: Tue, 14 Apr 2020 14:58:36 +0200 Subject: [PATCH 2/8] pytest --show-capture=yes --- scripts/test-py3.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/scripts/test-py3.sh b/scripts/test-py3.sh index eaa3d07451d..530a2e8c992 100755 --- a/scripts/test-py3.sh +++ b/scripts/test-py3.sh @@ -16,7 +16,7 @@ pytest openlibrary/catalog/marc/tests/test_marc.py || true pytest openlibrary/catalog/marc/tests/test_parse.py || true pytest openlibrary/tests/catalog/test_get_ia.py || true pytest openlibrary/coverstore/tests/test_doctests.py || true -pytest openlibrary/plugins/openlibrary/tests/test_home.py || true +pytest --show-capture=yes openlibrary/plugins/openlibrary/tests/test_home.py || true pytest openlibrary/plugins/upstream/tests/test_merge_authors.py || true exit ${RETURN_CODE} From dd5515fd041721e2df41dd342a299f51d1169f66 Mon Sep 17 00:00:00 2001 From: cclauss Date: Tue, 14 Apr 2020 15:11:00 +0200 Subject: [PATCH 3/8] pytest --show-capture=all --- scripts/test-py3.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/scripts/test-py3.sh b/scripts/test-py3.sh index 530a2e8c992..95ca2b190d9 100755 --- a/scripts/test-py3.sh +++ b/scripts/test-py3.sh @@ -16,7 +16,7 @@ pytest openlibrary/catalog/marc/tests/test_marc.py || true pytest openlibrary/catalog/marc/tests/test_parse.py || true pytest openlibrary/tests/catalog/test_get_ia.py || true pytest openlibrary/coverstore/tests/test_doctests.py || true -pytest --show-capture=yes openlibrary/plugins/openlibrary/tests/test_home.py || true +pytest --show-capture=all openlibrary/plugins/openlibrary/tests/test_home.py || true pytest openlibrary/plugins/upstream/tests/test_merge_authors.py || true exit ${RETURN_CODE} From d1ca08ee565a51d0ca16cd8e0dcd519046640466 Mon Sep 17 00:00:00 2001 From: cclauss Date: Tue, 14 Apr 2020 16:45:06 +0200 Subject: [PATCH 4/8] pytest --show-capture=all --- openlibrary/mocks/mock_infobase.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/openlibrary/mocks/mock_infobase.py b/openlibrary/mocks/mock_infobase.py index d8edd75b933..eb7c7c50ea4 100644 --- a/openlibrary/mocks/mock_infobase.py +++ b/openlibrary/mocks/mock_infobase.py @@ -100,11 +100,14 @@ def quicksave(self, key, type="/type/object", **kw): foo = mock_site.quicksave("/books/OL1M", "/type/edition", title="Foo") """ + import logging + logger = logging.getLogger(__name__) query = { "key": key, "type": {"key": type}, } query.update(kw) + logger.error("quicksave(%s) query=%s" % (key, query)) self.save(query) return self.get(key) From 35e759c546c5a370385bebe3f262ca0772749409 Mon Sep 17 00:00:00 2001 From: cclauss Date: Tue, 14 Apr 2020 16:56:56 +0200 Subject: [PATCH 5/8] log format_book_data --- openlibrary/mocks/mock_infobase.py | 3 --- openlibrary/plugins/openlibrary/home.py | 1 + 2 files changed, 1 insertion(+), 3 deletions(-) diff --git a/openlibrary/mocks/mock_infobase.py b/openlibrary/mocks/mock_infobase.py index eb7c7c50ea4..d8edd75b933 100644 --- a/openlibrary/mocks/mock_infobase.py +++ b/openlibrary/mocks/mock_infobase.py @@ -100,14 +100,11 @@ def quicksave(self, key, type="/type/object", **kw): foo = mock_site.quicksave("/books/OL1M", "/type/edition", title="Foo") """ - import logging - logger = logging.getLogger(__name__) query = { "key": key, "type": {"key": type}, } query.update(kw) - logger.error("quicksave(%s) query=%s" % (key, query)) self.save(query) return self.get(key) diff --git a/openlibrary/plugins/openlibrary/home.py b/openlibrary/plugins/openlibrary/home.py index 90f9d6d94d6..ee1cd42f6a1 100644 --- a/openlibrary/plugins/openlibrary/home.py +++ b/openlibrary/plugins/openlibrary/home.py @@ -238,6 +238,7 @@ def get_authors(doc): work = book.works and book.works[0] d.authors = get_authors(work if work else book) cover = work.get_cover() if work and work.get_cover() else book.get_cover() + logger.error("format_book_data(%s) work=%s, d.authors=%s" % (book, work, d.authors)) if cover: d.cover_url = cover.url("M") From 35d3b23a5fdb5869806c3f209199f8f7e6684102 Mon Sep 17 00:00:00 2001 From: cclauss Date: Tue, 14 Apr 2020 17:27:01 +0200 Subject: [PATCH 6/8] log mock_infobase.py --- openlibrary/mocks/mock_infobase.py | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/openlibrary/mocks/mock_infobase.py b/openlibrary/mocks/mock_infobase.py index d8edd75b933..ccdbe355be9 100644 --- a/openlibrary/mocks/mock_infobase.py +++ b/openlibrary/mocks/mock_infobase.py @@ -106,6 +106,11 @@ def quicksave(self, key, type="/type/object", **kw): } query.update(kw) self.save(query) + + import logging + logger = logging.getLogger(__name__) + logger.error("quicksave(%s) query=%s -> %s" % (key, query, self.get(key))) + return self.get(key) def _make_changeset(self, timestamp, kind, comment, data, changes, author=None): From e203e17ee82dc2284ac752c0675fafedf9d56e23 Mon Sep 17 00:00:00 2001 From: cclauss Date: Thu, 16 Apr 2020 17:54:52 +0200 Subject: [PATCH 7/8] Revert changes to mock_infobase.py and home.py --- openlibrary/mocks/mock_infobase.py | 5 ----- openlibrary/plugins/openlibrary/home.py | 1 - 2 files changed, 6 deletions(-) diff --git a/openlibrary/mocks/mock_infobase.py b/openlibrary/mocks/mock_infobase.py index ccdbe355be9..d8edd75b933 100644 --- a/openlibrary/mocks/mock_infobase.py +++ b/openlibrary/mocks/mock_infobase.py @@ -106,11 +106,6 @@ def quicksave(self, key, type="/type/object", **kw): } query.update(kw) self.save(query) - - import logging - logger = logging.getLogger(__name__) - logger.error("quicksave(%s) query=%s -> %s" % (key, query, self.get(key))) - return self.get(key) def _make_changeset(self, timestamp, kind, comment, data, changes, author=None): diff --git a/openlibrary/plugins/openlibrary/home.py b/openlibrary/plugins/openlibrary/home.py index ee1cd42f6a1..90f9d6d94d6 100644 --- a/openlibrary/plugins/openlibrary/home.py +++ b/openlibrary/plugins/openlibrary/home.py @@ -238,7 +238,6 @@ def get_authors(doc): work = book.works and book.works[0] d.authors = get_authors(work if work else book) cover = work.get_cover() if work and work.get_cover() else book.get_cover() - logger.error("format_book_data(%s) work=%s, d.authors=%s" % (book, work, d.authors)) if cover: d.cover_url = cover.url("M") From b702c0680c3d84572b592ec99318227e955ffd00 Mon Sep 17 00:00:00 2001 From: cclauss Date: Thu, 16 Apr 2020 18:02:22 +0200 Subject: [PATCH 8/8] test_merge_authors.py must now pass --- scripts/test-py3.sh | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/scripts/test-py3.sh b/scripts/test-py3.sh index 95ca2b190d9..d83d21ed940 100755 --- a/scripts/test-py3.sh +++ b/scripts/test-py3.sh @@ -7,16 +7,14 @@ pytest openlibrary/catalog openlibrary/coverstore openlibrary/mocks openlibrary/ --ignore=openlibrary/catalog/marc/tests/test_parse.py \ --ignore=openlibrary/tests/catalog/test_get_ia.py \ --ignore=openlibrary/coverstore/tests/test_doctests.py \ - --ignore=openlibrary/plugins/openlibrary/tests/test_home.py \ - --ignore=openlibrary/plugins/upstream/tests/test_merge_authors.py + --ignore=openlibrary/plugins/openlibrary/tests/test_home.py RETURN_CODE=$? pytest openlibrary/catalog/marc/tests/test_get_subjects.py || true pytest openlibrary/catalog/marc/tests/test_marc.py || true pytest openlibrary/catalog/marc/tests/test_parse.py || true pytest openlibrary/tests/catalog/test_get_ia.py || true -pytest openlibrary/coverstore/tests/test_doctests.py || true +pytest --show-capture=all openlibrary/coverstore/tests/test_doctests.py || true pytest --show-capture=all openlibrary/plugins/openlibrary/tests/test_home.py || true -pytest openlibrary/plugins/upstream/tests/test_merge_authors.py || true exit ${RETURN_CODE}