Betamax issues

[FriedrichFroebel]

I recently stumbled upon some strange issues which seem to be related to our Betamax setup. One issue is already documented in #186, although I am not sure why.

Additionally, #193 (comment) just unveiled that recording cassettes seems to fail if there is more than one method inside a test class. Example:

class TestCacheIssues(LoggedInTest):
    def test_author(self):
        with self.subTest("normal"):
            cache = Cache(self.gc, "GC4808G")
            with self.recorder.use_cassette("cache_author_normal"):
                self.assertEqual("Bifurkační tým", cache.author)

        with self.subTest("deleted"):
            cache = Cache(self.gc, "GC1MX0C")
            with self.recorder.use_cassette("cache_author_deleted"):
                self.assertIsNone(cache.author)

    def test_quick_load(self):
        cache = Cache(self.gc, "GC8CKQQ")
        with self.recorder.use_cassette("cache_status_enabled_load_quick"):
            cache.load_quick()
            self.assertEqual('', cache.status)

For me, recording the test_quick_load cassette failed while test_author had existing cassettes, but was executed. Simply adding a comment to test_author allowed me to record the cassette for test_quick_load. As soon as the cassettes are recorded, everything seems to work correctly.

Command: PYCACHING_TEST_USERNAME=USERNAME PYCACHING_TEST_PASSWORD=PASSWORD pytest test/test_cache.py::TestCacheIssues --verbose -rsx --log-cli-level=10.

Relevant excerpt from the output (logging res.request.header and res.text before res.raise_for_status in pycaching.geocaching.Geocaching._request) - I have been surprised by the quite verbose output here as well:

=============================================================================== FAILURES ================================================================================
____________________________________________________________________ TestCacheIssues.test_quick_load ____________________________________________________________________

self = <pycaching.geocaching.Geocaching object at 0x7f410d8ff8b0>, url = 'http://tiles01.geocaching.com/map.details', expect = 'json', method = 'GET', login_check = True
kwargs = {'params': {'i': 'GC8CKQQ'}}, res = <Response [500]>, logging = <module 'logging' from '/usr/lib/python3.10/logging/__init__.py'>
logger = <Logger pycaching.geocaching (DEBUG)>

    def _request(self, url, *, expect="soup", method="GET", login_check=True, **kwargs):
        """
        Do a HTTP request and return a response based on expect param.
    
        :param str url: Request target.
        :param str method: HTTP method to use.
        :param str expect: Expected type of data (either :code:`soup`, :code:`json` or :code:`raw`).
        :param bool login_check: Whether to check if user is logged in or not.
        :param kwargs: Passed to `requests.request
            <http://docs.python-requests.org/en/latest/api/#requests.request>`_ as is.
        """
        # check login unless explicitly turned off
        if login_check and not self._logged_in:
            raise NotLoggedInException("Login is needed.")
    
        url = url if "//" in url else urljoin(self._baseurl, url)
    
        try:
            res = self._session.request(method, url, **kwargs)
            import logging
            logger = logging.getLogger(__name__)
            logger.info(res.request.headers)
            logger.info(res.text)
>           res.raise_for_status()

pycaching/geocaching.py:89: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <Response [500]>

    def raise_for_status(self):
        """Raises :class:`HTTPError`, if one occurred."""
    
        http_error_msg = ""
        if isinstance(self.reason, bytes):
            # We attempt to decode utf-8 first because some servers
            # choose to localize their reason strings. If the string
            # isn't utf-8, we fall back to iso-8859-1 for all other
            # encodings. (See PR #3538)
            try:
                reason = self.reason.decode("utf-8")
            except UnicodeDecodeError:
                reason = self.reason.decode("iso-8859-1")
        else:
            reason = self.reason
    
        if 400 <= self.status_code < 500:
            http_error_msg = (
                f"{self.status_code} Client Error: {reason} for url: {self.url}"
            )
    
        elif 500 <= self.status_code < 600:
            http_error_msg = (
                f"{self.status_code} Server Error: {reason} for url: {self.url}"
            )
    
        if http_error_msg:
>           raise HTTPError(http_error_msg, response=self)
E           requests.exceptions.HTTPError: 500 Server Error: Internal Server Error for url: https://tiles01.geocaching.com/map.details?i=GC8CKQQ

.env/lib/python3.10/site-packages/requests/models.py:1021: HTTPError

The above exception was the direct cause of the following exception:

self = <test.test_cache.TestCacheIssues testMethod=test_quick_load>

    def test_quick_load(self):
        cache = Cache(self.gc, "GC8CKQQ")
        with self.recorder.use_cassette("cache_status_enabled_load_quick"):
>           cache.load_quick()

test/test_cache.py:425: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
pycaching/cache.py:845: in load_quick
    res = self.geocaching._request(self._urls["tiles_server"], params={"i": self.wp}, expect="json")
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <pycaching.geocaching.Geocaching object at 0x7f410d8ff8b0>, url = 'http://tiles01.geocaching.com/map.details', expect = 'json', method = 'GET', login_check = True
kwargs = {'params': {'i': 'GC8CKQQ'}}, res = <Response [500]>, logging = <module 'logging' from '/usr/lib/python3.10/logging/__init__.py'>
logger = <Logger pycaching.geocaching (DEBUG)>

    def _request(self, url, *, expect="soup", method="GET", login_check=True, **kwargs):
        """
        Do a HTTP request and return a response based on expect param.
    
        :param str url: Request target.
        :param str method: HTTP method to use.
        :param str expect: Expected type of data (either :code:`soup`, :code:`json` or :code:`raw`).
        :param bool login_check: Whether to check if user is logged in or not.
        :param kwargs: Passed to `requests.request
            <http://docs.python-requests.org/en/latest/api/#requests.request>`_ as is.
        """
        # check login unless explicitly turned off
        if login_check and not self._logged_in:
            raise NotLoggedInException("Login is needed.")
    
        url = url if "//" in url else urljoin(self._baseurl, url)
    
        try:
            res = self._session.request(method, url, **kwargs)
            import logging
            logger = logging.getLogger(__name__)
            logger.info(res.request.headers)
            logger.info(res.text)
            res.raise_for_status()
    
            # return bs4.BeautifulSoup, JSON dict or raw requests.Response
            if expect == "soup":
                return bs4.BeautifulSoup(res.text, "html.parser")
            elif expect == "json":
                return res.json()
            elif expect == "raw":
                return res
    
        except requests.exceptions.RequestException as e:
            if e.response.status_code == 429:  # Handle rate limiting errors
                raise TooManyRequestsError(
                    url, rate_limit_reset=int(e.response.headers.get("x-rate-limit-reset", "0"))
                ) from e
>           raise Error("Cannot load page: {} {}".format(url, e.response.status_code)) from e
E           pycaching.errors.Error: Cannot load page: http://tiles01.geocaching.com/map.details 500

pycaching/geocaching.py:104: Error
--------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
DEBUG    urllib3.connectionpool:connectionpool.py:228 Starting new HTTP connection (1): tiles01.geocaching.com:80
DEBUG    urllib3.connectionpool:connectionpool.py:456 http://tiles01.geocaching.com:80 "GET /map.details?i=GC8CKQQ HTTP/1.1" 302 0
DEBUG    urllib3.connectionpool:connectionpool.py:1003 Starting new HTTPS connection (1): tiles01.geocaching.com:443
DEBUG    urllib3.connectionpool:connectionpool.py:456 https://tiles01.geocaching.com:443 "GET /map.details?i=GC8CKQQ HTTP/1.1" 500 5582
INFO     pycaching.geocaching:geocaching.py:87 {'User-Agent': 'python-requests/2.28.1', 'Accept-Encoding': 'gzip, deflate', 'Accept': '*/*', 'Connection': 'keep-alive', 'Cookie': 'gspkauth=<AUTH COOKIE>'}
INFO     pycaching.geocaching:geocaching.py:88 <!DOCTYPE html>
<html>
    <head>
        <title>A potentially dangerous Request.Cookies value was detected from the client (gspkauth=&quot;&lt;AUTH COOKIE&gt;&quot;).</title>
        <meta name="viewport" content="width=device-width" />
        <style>
         body {font-family:"Verdana";font-weight:normal;font-size: .7em;color:black;} 
         p {font-family:"Verdana";font-weight:normal;color:black;margin-top: -5px}
         b {font-family:"Verdana";font-weight:bold;color:black;margin-top: -5px}
         H1 { font-family:"Verdana";font-weight:normal;font-size:18pt;color:red }
         H2 { font-family:"Verdana";font-weight:normal;font-size:14pt;color:maroon }
         pre {font-family:"Consolas","Lucida Console",Monospace;font-size:11pt;margin:0;padding:0.5em;line-height:14pt}
         .marker {font-weight: bold; color: black;text-decoration: none;}
         .version {color: gray;}
         .error {margin-bottom: 10px;}
         .expandable { text-decoration:underline; font-weight:bold; color:navy; cursor:hand; }
         @media screen and (max-width: 639px) {
          pre { width: 440px; overflow: auto; white-space: pre-wrap; word-wrap: break-word; }
         }
         @media screen and (max-width: 479px) {
          pre { width: 280px; }
         }
        </style>
    </head>

    <body bgcolor="white">

            <span><H1>Server Error in '/' Application.<hr width=100% size=1 color=silver></H1>

            <h2> <i>A potentially dangerous Request.Cookies value was detected from the client (gspkauth=&quot;&lt;AUTH COOKIE&gt;&quot;).</i> </h2></span>

            <font face="Arial, Helvetica, Geneva, SunSans-Regular, sans-serif ">

            <b> Description: </b>ASP.NET has detected data in the request that is potentially dangerous because it might include HTML markup or script. The data might represent an attempt to compromise the security of your application, such as a cross-site scripting attack. If this type of input is appropriate in your application, you can include code in a web page to explicitly allow it. For more information, see http://go.microsoft.com/fwlink/?LinkID=212874.
            <br><br>

            <b> Exception Details: </b>System.Web.HttpRequestValidationException: A potentially dangerous Request.Cookies value was detected from the client (gspkauth=&quot;&lt;AUTH COOKIE&gt;&quot;).<br><br>

            <b>Source Error:</b> <br><br>

            <table width=100% bgcolor="#ffffcc">
               <tr>
                  <td>
                      <code>

An unhandled exception was generated during the execution of the current web request. Information regarding the origin and location of the exception can be identified using the exception stack trace below.</code>

                  </td>
               </tr>
            </table>

            <br>

            <b>Stack Trace:</b> <br><br>

            <table width=100% bgcolor="#ffffcc">
               <tr>
                  <td>
                      <code><pre>

[HttpRequestValidationException (0x80004005): A potentially dangerous Request.Cookies value was detected from the client (gspkauth=&quot;&lt;AUTH COOKIE&gt;&quot;).]
   System.Web.HttpRequest.ValidateString(String value, String collectionKey, RequestValidationSource requestCollection) +9933216
   System.Web.HttpRequest.ValidateCookieCollection(HttpCookieCollection cc) +195
   System.Web.HttpRequest.get_Cookies() +60
   System.Web.HttpRequest.get_Item(String key) +69
   Groundspeak.MapOverlay.MapDetailsHandler.ProcessRequest(HttpContext context) in E:\TeamCity\work\db9a3e4bede42c15\Src\Common\Groundspeak.MapOverlay\Groundspeak.MapOverlay\Handlers\MapDetailsHandler.cs:44
   System.Web.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() +188
   System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step) +48
   System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean&amp; completedSynchronously) +71
</pre></code>

                  </td>
               </tr>
            </table>

            <br>

            <hr width=100% size=1 color=silver>

            <b>Version Information:</b>&nbsp;Microsoft .NET Framework Version:4.0.30319; ASP.NET Version:4.7.3930.0

            </font>

    </body>
</html>
<!-- 
[HttpRequestValidationException]: A potentially dangerous Request.Cookies value was detected from the client (gspkauth=&quot;&lt;AUTH COOKIE&gt;&quot;).
   at System.Web.HttpRequest.ValidateString(String value, String collectionKey, RequestValidationSource requestCollection)
   at System.Web.HttpRequest.ValidateCookieCollection(HttpCookieCollection cc)
   at System.Web.HttpRequest.get_Cookies()
   at System.Web.HttpRequest.get_Item(String key)
   at Groundspeak.MapOverlay.MapDetailsHandler.ProcessRequest(HttpContext context) in E:\TeamCity\work\db9a3e4bede42c15\Src\Common\Groundspeak.MapOverlay\Groundspeak.MapOverlay\Handlers\MapDetailsHandler.cs:line 44
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)
--><!-- 
This error page might contain sensitive information because ASP.NET is configured to show verbose error messages using &lt;customErrors mode="Off"/&gt;. Consider using &lt;customErrors mode="On"/&gt; or &lt;customErrors mode="RemoteOnly"/&gt; in production environments.-->

[FriedrichFroebel]

@jarhill0 Do you have any idea on how to fix this, since you mostly did the corresponding implementation in #95?

[jarhill0]

Hmm, I don't really know, sorry. It's been a while since I made that change and I haven't been closely involved in this project for quite some time

[FriedrichFroebel]

@jarhill0 No big deal, I just thought you might have an idea here why the replacement logic seems to act wrong. Thanks for your answer anyway.

[BelKed]

I was getting some errors (401 Client Error: Unauthorized for url: …) while recording cassettes, so I managed to find a workaround. Seems like Betamax doesn't send all cookies — the most important one (gspkauth) isn't sent in the request.

---

My solution was quite simple — I added this piece into every test which needed recording a cassette:

import requests

self.gc._session.cookies.set_cookie(
    requests.cookies.create_cookie(
        name="gspkauth",
        value="TOKEN_VALUE",
    )
)

---

Example:

def test_something(self):
    import requests

    self.gc._session.cookies.set_cookie(
        requests.cookies.create_cookie(
            name="gspkauth",
            value="TOKEN_VALUE",
        )
    )

    with self.recorder.use_cassette("some_cassette"):
        cache = self.gc._try_getting_cache_from_guid("cache_guid")
        self.assertEqual("cache_name", cache.name)

---

^{This is mostly a note for me, so I wouldn't need to find the workaround again 😄}