Debug issue from gh440

[erpel]

In #440 / #441 a callback was introduced. Using the response of the callback causes issues for our setup.
This MR is an attempt to debug the situation and hopefully finding a way that works for @thecaffiend as well as our setup.

[thecaffiend]

Gave it a quick shot and I was able to go through the whole flow including duo push and get logged in. Unfortunately that's all I'll be able to get to today.

That said, there is an error in JSON decoding (that ends up getting ignored) that i have not looked into other than to see that it's happening in the try/except you added:

2025-08-05 09:44:43,644 [_duo_universal_prompt_authenticator _duo_universal_prompt_authenticator.py:_initiate_authentication] [543774-MainProcess] [140332594344640-MainThread] - ERROR: Error doing callback
Traceback (most recent call last):
  File "/home/lp76/.local/share/mamba/envs/aws-adfs-erpel/lib/python3.11/site-packages/requests/models.py", line 976, in json
    return complexjson.loads(self.text, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/lp76/.local/share/mamba/envs/aws-adfs-erpel/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/lp76/.local/share/mamba/envs/aws-adfs-erpel/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/lp76/.local/share/mamba/envs/aws-adfs-erpel/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/lp76/development/adfs/erpel-aws-adfs/aws_adfs/_duo_universal_prompt_authenticator.py", line 508, in _initiate_authentication
    callback_json = callback_response.json()
                    ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/lp76/.local/share/mamba/envs/aws-adfs-erpel/lib/python3.11/site-packages/requests/models.py", line 980, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
requests.exceptions.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
2025-08-05 09:44:43,646 [_duo_universal_prompt_authenticator _duo_universal_prompt_authenticator.py:_initiate_authentication] [543774-MainProcess] [140332594344640-MainThread] - ERROR: ignoring: Expecting value: line 1 column 1 (char 0)
2025-08-05 09:44:43,646 [_duo_universal_prompt_authenticator _duo_universal_prompt_authenticator.py:_initiate_authentication] [543774-MainProcess] [140332594344640-MainThread] - INFO: after callback
Waiting for additional authentication
Triggering authentication method: 'Duo Push' with 'phone1'

Again, it ultimately lets me in with a push even with the above error.

[erpel]

I get the same error - initially I thought it happened because I used the wrong response for it. Since I can reproduce with our setup as well - I can try to debug this.

It would be nice if we could get the trace (run with debug logging) of the http request just before this error happens. Would be interesting to see the comparison between our two environments. - I think the error happening does mean, that it should work for your setup even if nothing is done with the response from this callback. I'll try to add a few command line switches or sth. to let us experiment with different procedures without requiring code changes every time.

Thanks for taking the time to test this.

[thecaffiend]

Sure, np. You just looking for the block starting with something like [_duo_universal_prompt_authenticator _duo_universal_prompt_authenticator.py:_initiate_authentication] [xxxxxx-MainProcess] [xxxxxxxxxxxxxxxx-MainThread] and up to the error, or less/more than that?

[erpel]

That would be sufficient. I tried to reproduce the issue somewhat and improve logging but could not reproduce this anymore.
Testing on the latest branch would be terrific but I don't see significant changes to what you tested with.

I'd be looking for this part specifically, to understand why the response is not parsable as json "sometimes":

 ================================================================================
Request:
* url: https://api-273...
* headers: {'User-Agent': 'python-requests/2.32.4', 'Accept-Encoding': 'gzip, deflate', 'Accept': 'text/plain, */*; q=0.01', 'Connection': 'keep-alive', 'Accept-Language': 'en', 'Cookie': 'hac|DUSZFI323T1KW0CARLIX|x="x==|1755507941|x"'}
* body: None
================================================================================
Response:
* status: 200
* headers: {'Server': 'Duo/1.0', 'Date': 'Mon, 18 Aug 2025 11:01:58 GMT', 'Content-Type': 'text/html; charset=UTF-8', 'Transfer-Encoding': 'chunked', 'Connection': 'keep-alive', 'Cache-Control': 'no-store', 'Pragma': 'no-cache', 'Referrer-Policy': 'strict-origin-when-cross-origin', 'P3p': 'CP="IDC DSP COR ADM DEVi TAIi PSA PSD IVAi IVDi CONi HIS OUR IND CNT"', 'Origin-Trial': 'AhDE/x+xbc/x==', 'Etag': 'W/"94ee09d3471aex7cd5d8f3a9a9f"', 'Set-Cookie': 'sid|678b69e6-b12e-4b71-b295x481f19a"; expires=Mon, 18 Aug 2025 11:16:58 GMT; HttpOnly; Path=/; SameSite=None; Secure, _xsrf|678b69e6-b12e-4b71-b295-83a8c54c10f7="ZmQ5ZDx702d071e9919cf1fd7020"; expires=Mon, 18 Aug 2025 12:31:58 GMT; HttpOnly; Path=/; SameSite=None; Secure', 'Strict-Transport-Security': 'max-age=31536000', 'Content-Security-Policy': "default-src 'self'; frame-src 'self' ; img-src 'self'  ; connect-src 'self'     ", 'X-Content-Type-Options': 'nosniff', 'Content-Encoding': 'gzip'}
* body: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN"
"http://www.w3.org/TR/html4/loose.dtd">
<html>
<head>
…