Handle errors better especialyl for streaming (Azure-Samples#884)

CONTRIBUTING.md

@@ -108,9 +108,19 @@ playwright install --with-deps
 Run the tests:
 
 ```
-python3 -m pytest tests/e2e.py
+python3 -m pytest tests/e2e.py --tracing=retain-on-failure
 ```
 
+When a failure happens, the trace zip will be saved in the test-results folder.
+You can view that using the Playwright CLI:
+
+```
+playwright show-trace test-results/<trace-zip>
+```
+
+You can also use the online trace viewer at https://trace.playwright.dev/
+
+
 ## <a name="style"></a> Code Style
 
 This codebase includes several languages: TypeScript, Python, Bicep, Powershell, and Bash.
@@ -135,3 +145,5 @@ Run `black` to format a file:
 ```
 python3 -m black <path-to-file>
 ```
+
+If you followed the steps above to install the pre-commit hooks, then you can just wait for those hooks to run `ruff` and `black` for you.

app/backend/app.py

@@ -40,6 +40,10 @@
 CONFIG_BLOB_CONTAINER_CLIENT = "blob_container_client"
 CONFIG_AUTH_CLIENT = "auth_client"
 CONFIG_SEARCH_CLIENT = "search_client"
+ERROR_MESSAGE = """The app encountered an error processing your request.
+If you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.
+Error type: {error_type}
+"""
 
 bp = Blueprint("routes", __name__, static_folder="static")
 
@@ -93,6 +97,10 @@ async def content_file(path: str):
     return await send_file(blob_file, mimetype=mime_type, as_attachment=False, attachment_filename=path)
 
 
+def error_dict(error: Exception) -> dict:
+    return {"error": ERROR_MESSAGE.format(error_type=type(error))}
+
+
 @bp.route("/ask", methods=["POST"])
 async def ask():
     if not request.is_json:
@@ -110,14 +118,18 @@ async def ask():
                 request_json["messages"], context=context, session_state=request_json.get("session_state")
             )
         return jsonify(r)
-    except Exception as e:
-        logging.exception("Exception in /ask")
-        return jsonify({"error": str(e)}), 500
+    except Exception as error:
+        logging.exception("Exception in /ask: %s", error)
+        return jsonify(error_dict(error)), 500
 
 
 async def format_as_ndjson(r: AsyncGenerator[dict, None]) -> AsyncGenerator[str, None]:
-    async for event in r:
-        yield json.dumps(event, ensure_ascii=False) + "\n"
+    try:
+        async for event in r:
+            yield json.dumps(event, ensure_ascii=False) + "\n"
+    except Exception as e:
+        logging.exception("Exception while generating response stream: %s", e)
+        yield json.dumps(error_dict(e))
 
 
 @bp.route("/chat", methods=["POST"])
@@ -142,9 +154,9 @@ async def chat():
             response = await make_response(format_as_ndjson(result))
             response.timeout = None  # type: ignore
             return response
-    except Exception as e:
-        logging.exception("Exception in /chat")
-        return jsonify({"error": str(e)}), 500
+    except Exception as error:
+        logging.exception("Exception in /chat: %s", error)
+        return jsonify(error_dict(error)), 500
 
 
 # Send MSAL.js settings to the client UI

app/frontend/src/pages/chat/Chat.tsx

@@ -73,6 +73,8 @@ const Chat = () => {
                 } else if (event["choices"] && event["choices"][0]["context"]) {
                     // Update context with new keys from latest event
                     askResponse.choices[0].context = { ...askResponse.choices[0].context, ...event["choices"][0]["context"] };
+                } else if (event["error"]) {
+                    throw Error(event["error"]);
                 }
             }
         } finally {

tests/e2e.py

@@ -291,3 +291,81 @@ def handle(route: Route):
 
     expect(page.get_by_text("Whats the dental plan?")).to_be_visible()
     expect(page.get_by_text("The capital of France is Paris.")).to_be_visible()
+
+
+def test_ask_with_error(page: Page, live_server_url: str):
+    # Set up a mock route to the /ask endpoint
+    def handle(route: Route):
+        # Read the JSON from our snapshot results and return as the response
+        f = open("tests/snapshots/test_app/test_ask_handle_exception/client0/result.json")
+        json = f.read()
+        f.close()
+        route.fulfill(body=json, status=500)
+
+    page.route("*/**/ask", handle)
+    page.goto(live_server_url)
+    expect(page).to_have_title("GPT + Enterprise data | Sample")
+
+    page.get_by_role("link", name="Ask a question").click()
+    page.get_by_placeholder("Example: Does my plan cover annual eye exams?").click()
+    page.get_by_placeholder("Example: Does my plan cover annual eye exams?").fill("Whats the dental plan?")
+    page.get_by_label("Ask question button").click()
+
+    expect(page.get_by_text("Whats the dental plan?")).to_be_visible()
+    expect(page.get_by_text("The app encountered an error processing your request.")).to_be_visible()
+
+
+def test_chat_with_error_nonstreaming(page: Page, live_server_url: str):
+    # Set up a mock route to the /chat_stream endpoint
+    def handle(route: Route):
+        # Read the JSON from our snapshot results and return as the response
+        f = open("tests/snapshots/test_app/test_chat_handle_exception/client0/result.json")
+        json = f.read()
+        f.close()
+        route.fulfill(body=json, status=500)
+
+    page.route("*/**/chat", handle)
+
+    # Check initial page state
+    page.goto(live_server_url)
+    expect(page).to_have_title("GPT + Enterprise data | Sample")
+    expect(page.get_by_role("button", name="Developer settings")).to_be_enabled()
+    page.get_by_role("button", name="Developer settings").click()
+    page.get_by_text("Stream chat completion responses").click()
+    page.locator("button").filter(has_text="Close").click()
+
+    # Ask a question and wait for the message to appear
+    page.get_by_placeholder("Type a new question (e.g. does my plan cover annual eye exams?)").click()
+    page.get_by_placeholder("Type a new question (e.g. does my plan cover annual eye exams?)").fill(
+        "Whats the dental plan?"
+    )
+    page.get_by_label("Ask question button").click()
+
+    expect(page.get_by_text("Whats the dental plan?")).to_be_visible()
+    expect(page.get_by_text("The app encountered an error processing your request.")).to_be_visible()
+
+
+def test_chat_with_error_streaming(page: Page, live_server_url: str):
+    # Set up a mock route to the /chat_stream endpoint
+    def handle(route: Route):
+        # Read the JSONL from our snapshot results and return as the response
+        f = open("tests/snapshots/test_app/test_chat_handle_exception_streaming/client0/result.jsonlines")
+        jsonl = f.read()
+        f.close()
+        route.fulfill(body=jsonl, status=200, headers={"Transfer-encoding": "Chunked"})
+
+    page.route("*/**/chat", handle)
+
+    # Check initial page state
+    page.goto(live_server_url)
+    expect(page).to_have_title("GPT + Enterprise data | Sample")
+
+    # Ask a question and wait for the message to appear
+    page.get_by_placeholder("Type a new question (e.g. does my plan cover annual eye exams?)").click()
+    page.get_by_placeholder("Type a new question (e.g. does my plan cover annual eye exams?)").fill(
+        "Whats the dental plan?"
+    )
+    page.get_by_label("Ask question button").click()
+
+    expect(page.get_by_text("Whats the dental plan?")).to_be_visible()
+    expect(page.get_by_text("The app encountered an error processing your request.")).to_be_visible()

tests/snapshots/test_app/test_ask_handle_exception/client0/result.json

@@ -0,0 +1,3 @@
+{
+    "error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'ZeroDivisionError'>\n"
+}

tests/snapshots/test_app/test_ask_handle_exception/client1/result.json

@@ -0,0 +1,3 @@
+{
+    "error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'ZeroDivisionError'>\n"
+}

tests/snapshots/test_app/test_chat_handle_exception/client0/result.json

@@ -0,0 +1,3 @@
+{
+    "error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'ZeroDivisionError'>\n"
+}

tests/snapshots/test_app/test_chat_handle_exception/client1/result.json

@@ -0,0 +1,3 @@
+{
+    "error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'ZeroDivisionError'>\n"
+}

tests/snapshots/test_app/test_chat_handle_exception_streaming/client0/result.jsonlines

@@ -0,0 +1 @@
+{"error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'ZeroDivisionError'>\n"}

tests/snapshots/test_app/test_chat_handle_exception_streaming/client1/result.jsonlines

@@ -0,0 +1 @@
+{"error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'ZeroDivisionError'>\n"}

tests/test_app.py

@@ -46,6 +46,23 @@ async def test_ask_request_must_be_json(client):
     assert result["error"] == "request must be json"
 
 
+@pytest.mark.asyncio
+async def test_ask_handle_exception(client, monkeypatch, snapshot, caplog):
+    monkeypatch.setattr(
+        "approaches.retrievethenread.RetrieveThenReadApproach.run",
+        mock.Mock(side_effect=ZeroDivisionError("something bad happened")),
+    )
+
+    response = await client.post(
+        "/ask",
+        json={"messages": [{"content": "What is the capital of France?", "role": "user"}]},
+    )
+    assert response.status_code == 500
+    result = await response.get_json()
+    assert "Exception in /ask: something bad happened" in caplog.text
+    snapshot.assert_match(json.dumps(result, indent=4), "result.json")
+
+
 @pytest.mark.asyncio
 async def test_ask_rtr_text(client, snapshot):
     response = await client.post(
@@ -144,6 +161,39 @@ async def test_chat_request_must_be_json(client):
     assert result["error"] == "request must be json"
 
 
+@pytest.mark.asyncio
+async def test_chat_handle_exception(client, monkeypatch, snapshot, caplog):
+    monkeypatch.setattr(
+        "approaches.chatreadretrieveread.ChatReadRetrieveReadApproach.run",
+        mock.Mock(side_effect=ZeroDivisionError("something bad happened")),
+    )
+
+    response = await client.post(
+        "/chat",
+        json={"messages": [{"content": "What is the capital of France?", "role": "user"}]},
+    )
+    assert response.status_code == 500
+    result = await response.get_json()
+    assert "Exception in /chat: something bad happened" in caplog.text
+    snapshot.assert_match(json.dumps(result, indent=4), "result.json")
+
+
+@pytest.mark.asyncio
+async def test_chat_handle_exception_streaming(client, monkeypatch, snapshot, caplog):
+    monkeypatch.setattr(
+        "openai.ChatCompletion.acreate", mock.Mock(side_effect=ZeroDivisionError("something bad happened"))
+    )
+
+    response = await client.post(
+        "/chat",
+        json={"messages": [{"content": "What is the capital of France?", "role": "user"}], "stream": True},
+    )
+    assert response.status_code == 200
+    assert "Exception while generating response stream: something bad happened" in caplog.text
+    result = await response.get_data()
+    snapshot.assert_match(result, "result.jsonlines")
+
+
 @pytest.mark.asyncio
 async def test_chat_text(client, snapshot):
     response = await client.post(
@@ -457,3 +507,24 @@ async def gen():
 
     result = [line async for line in app.format_as_ndjson(gen())]
     assert result == ['{"a": "I ❤️ 🐍"}\n', '{"b": "Newlines inside \\n strings are fine"}\n']
+
+
+@pytest.mark.asyncio
+async def test_format_as_ndjson_error(caplog):
+    async def gen():
+        if False:
+            yield {"a": "I ❤️ 🐍"}
+        raise ZeroDivisionError("something bad happened")
+
+    result = [line async for line in app.format_as_ndjson(gen())]
+    assert "Exception while generating response stream: something bad happened\n" in caplog.text
+    assert result == [
+        '{"error": "The app encountered an error processing your request.\\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\\nError type: <class \'ZeroDivisionError\'>\\n"}'
+    ]
+
+
+def test_error_dict(caplog):
+    error = app.error_dict(Exception("test"))
+    assert error == {
+        "error": "The app encountered an error processing your request.\nIf you are an administrator of the app, view the full error in the logs. See aka.ms/appservice-logs for more information.\nError type: <class 'Exception'>\n"
+    }