From e5755be1c7eac37ded4730b449b34e897bddd949 Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Sat, 10 Jun 2023 10:01:47 +0300
Subject: [PATCH 1/8] Add trace and atrace functions for single event traces

---
 httpcore/_trace.py | 50 ++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 50 insertions(+)

diff --git a/httpcore/_trace.py b/httpcore/_trace.py
index afa47555..821094d2 100644
--- a/httpcore/_trace.py
+++ b/httpcore/_trace.py
@@ -5,6 +5,56 @@
 from ._models import Request
 
 
+def trace(
+    name: str,
+    logger: logging.Logger,
+    request: Optional[Request] = None,
+    kwargs: Optional[Dict[str, Any]] = None,
+) -> None:
+    trace_extension = None if request is None else request.extensions.get("trace")
+    prefix = logger.name.split(".")[-1]
+    info = kwargs or {}
+    debug = logger.isEnabledFor(logging.DEBUG)
+
+    if debug or trace_extension:
+        if trace_extension is not None:
+            prefix_and_name = f"{prefix}.{name}"
+            trace_extension(prefix_and_name, info)
+
+        if debug:
+            if not info:  # pragma: no cover
+                message = name
+            else:
+                args = " ".join([f"{key}={value!r}" for key, value in info.items()])
+                message = f"{name} {args}"
+            logger.debug(message)
+
+
+async def atrace(
+    name: str,
+    logger: logging.Logger,
+    request: Optional[Request] = None,
+    kwargs: Optional[Dict[str, Any]] = None,
+) -> None:
+    trace_extension = None if request is None else request.extensions.get("trace")
+    prefix = logger.name.split(".")[-1]
+    info = kwargs or {}
+    debug = logger.isEnabledFor(logging.DEBUG)
+
+    if debug or trace_extension:
+        if trace_extension is not None:
+            prefix_and_name = f"{prefix}.{name}"
+            await trace_extension(prefix_and_name, info)
+
+        if debug:
+            if not info:  # pragma: no cover
+                message = name
+            else:
+                args = " ".join([f"{key}={value!r}" for key, value in info.items()])
+                message = f"{name} {args}"
+            logger.debug(message)
+
+
 class Trace:
     def __init__(
         self,

From 8fa39eded04d7970bb3efe2569fe7204951e2ce8 Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Sat, 10 Jun 2023 10:03:03 +0300
Subject: [PATCH 2/8] Change trace events

---
 httpcore/_async/connection_pool.py   | 56 ++++++++++++++++++++++++
 httpcore/_sync/connection_pool.py    | 56 ++++++++++++++++++++++++
 tests/_async/test_connection_pool.py | 64 +++++++++++++++++++---------
 tests/_sync/test_connection_pool.py  | 64 +++++++++++++++++++---------
 unasync.py                           |  1 +
 5 files changed, 199 insertions(+), 42 deletions(-)

diff --git a/httpcore/_async/connection_pool.py b/httpcore/_async/connection_pool.py
index 935f34db..fee6c695 100644
--- a/httpcore/_async/connection_pool.py
+++ b/httpcore/_async/connection_pool.py
@@ -1,16 +1,22 @@
+import logging
 import ssl
 import sys
 from types import TracebackType
 from typing import AsyncIterable, AsyncIterator, Iterable, List, Optional, Type
 
+import httpcore
+
 from .._backends.auto import AutoBackend
 from .._backends.base import SOCKET_OPTION, AsyncNetworkBackend
 from .._exceptions import ConnectionNotAvailable, UnsupportedProtocol
 from .._models import Origin, Request, Response
 from .._synchronization import AsyncEvent, AsyncLock
+from .._trace import atrace
 from .connection import AsyncHTTPConnection
 from .interfaces import AsyncConnectionInterface, AsyncRequestInterface
 
+logger = logging.getLogger("httpcore.connection_pool")
+
 
 class RequestStatus:
     def __init__(self, request: Request):
@@ -161,8 +167,14 @@ async def _attempt_to_acquire_connection(self, status: RequestStatus) -> bool:
         # Reuse an existing connection if one is currently available.
         for idx, connection in enumerate(self._pool):
             if connection.can_handle_request(origin) and connection.is_available():
+                kwargs = {"connection": connection, "request": status.request}
+                await atrace("reuse_connection", logger, status.request, kwargs)
                 self._pool.pop(idx)
                 self._pool.insert(0, connection)
+                kwargs = {"request": status.request, "connection": connection}
+                await atrace(
+                    "assign_request_to_connection", logger, status.request, kwargs
+                )
                 status.set_connection(connection)
                 return True
 
@@ -171,6 +183,12 @@ async def _attempt_to_acquire_connection(self, status: RequestStatus) -> bool:
             for idx, connection in reversed(list(enumerate(self._pool))):
                 if connection.is_idle():
                     await connection.aclose()
+                    await atrace(
+                        "remove_connection",
+                        logger,
+                        None,
+                        kwargs={"connection": connection},
+                    )
                     self._pool.pop(idx)
                     break
 
@@ -180,7 +198,12 @@ async def _attempt_to_acquire_connection(self, status: RequestStatus) -> bool:
 
         # Otherwise create a new connection.
         connection = self.create_connection(origin)
+        await atrace(
+            "add_connection", logger, status.request, kwargs={"connection": connection}
+        )
         self._pool.insert(0, connection)
+        kwargs = {"request": status.request, "connection": connection}
+        await atrace("assign_request_to_connection", logger, status.request, kwargs)
         status.set_connection(connection)
         return True
 
@@ -192,6 +215,9 @@ async def _close_expired_connections(self) -> None:
         for idx, connection in reversed(list(enumerate(self._pool))):
             if connection.has_expired():
                 await connection.aclose()
+                await atrace(
+                    "remove_connection", logger, None, kwargs={"connection": connection}
+                )
                 self._pool.pop(idx)
 
         # If the pool size exceeds the maximum number of allowed keep-alive connections,
@@ -200,6 +226,9 @@ async def _close_expired_connections(self) -> None:
         for idx, connection in reversed(list(enumerate(self._pool))):
             if connection.is_idle() and pool_size > self._max_keepalive_connections:
                 await connection.aclose()
+                await atrace(
+                    "remove_connection", logger, None, kwargs={"connection": connection}
+                )
                 self._pool.pop(idx)
                 pool_size -= 1
 
@@ -222,6 +251,7 @@ async def handle_async_request(self, request: Request) -> Response:
         status = RequestStatus(request)
 
         async with self._pool_lock:
+            await atrace("add_request", logger, request, {"request": status.request})
             self._requests.append(status)
             await self._close_expired_connections()
             await self._attempt_to_acquire_connection(status)
@@ -235,9 +265,22 @@ async def handle_async_request(self, request: Request) -> Response:
                 # If we timeout here, or if the task is cancelled, then make
                 # sure to remove the request from the queue before bubbling
                 # up the exception.
+                if isinstance(exc, httpcore.PoolTimeout):
+                    await atrace(
+                        "timeout_waiting_for_connection",
+                        logger,
+                        status.request,
+                        {"request": status.request},
+                    )
                 async with self._pool_lock:
                     # Ensure only remove when task exists.
                     if status in self._requests:
+                        await atrace(
+                            "remove_request",
+                            logger,
+                            status.request,
+                            {"request": status.request},
+                        )
                         self._requests.remove(status)
                     raise exc
 
@@ -254,6 +297,13 @@ async def handle_async_request(self, request: Request) -> Response:
                 async with self._pool_lock:
                     # Maintain our position in the request queue, but reset the
                     # status so that the request becomes queued again.
+                    kwargs = {"request": status.request, "connection": connection}
+                    await atrace(
+                        "unassign_request_from_connection",
+                        logger,
+                        status.request,
+                        kwargs,
+                    )
                     status.unset_connection()
                     await self._attempt_to_acquire_connection(status)
             except BaseException as exc:
@@ -285,6 +335,12 @@ async def response_closed(self, status: RequestStatus) -> None:
         async with self._pool_lock:
             # Update the state of the connection pool.
             if status in self._requests:
+                await atrace(
+                    "remove_request",
+                    logger,
+                    status.request,
+                    {"request": status.request},
+                )
                 self._requests.remove(status)
 
             if connection.is_closed() and connection in self._pool:
diff --git a/httpcore/_sync/connection_pool.py b/httpcore/_sync/connection_pool.py
index f64334af..43f7d732 100644
--- a/httpcore/_sync/connection_pool.py
+++ b/httpcore/_sync/connection_pool.py
@@ -1,16 +1,22 @@
+import logging
 import ssl
 import sys
 from types import TracebackType
 from typing import Iterable, Iterator, Iterable, List, Optional, Type
 
+import httpcore
+
 from .._backends.sync import SyncBackend
 from .._backends.base import SOCKET_OPTION, NetworkBackend
 from .._exceptions import ConnectionNotAvailable, UnsupportedProtocol
 from .._models import Origin, Request, Response
 from .._synchronization import Event, Lock
+from .._trace import trace
 from .connection import HTTPConnection
 from .interfaces import ConnectionInterface, RequestInterface
 
+logger = logging.getLogger("httpcore.connection_pool")
+
 
 class RequestStatus:
     def __init__(self, request: Request):
@@ -161,8 +167,14 @@ def _attempt_to_acquire_connection(self, status: RequestStatus) -> bool:
         # Reuse an existing connection if one is currently available.
         for idx, connection in enumerate(self._pool):
             if connection.can_handle_request(origin) and connection.is_available():
+                kwargs = {"connection": connection, "request": status.request}
+                trace("reuse_connection", logger, status.request, kwargs)
                 self._pool.pop(idx)
                 self._pool.insert(0, connection)
+                kwargs = {"request": status.request, "connection": connection}
+                trace(
+                    "assign_request_to_connection", logger, status.request, kwargs
+                )
                 status.set_connection(connection)
                 return True
 
@@ -171,6 +183,12 @@ def _attempt_to_acquire_connection(self, status: RequestStatus) -> bool:
             for idx, connection in reversed(list(enumerate(self._pool))):
                 if connection.is_idle():
                     connection.close()
+                    trace(
+                        "remove_connection",
+                        logger,
+                        None,
+                        kwargs={"connection": connection},
+                    )
                     self._pool.pop(idx)
                     break
 
@@ -180,7 +198,12 @@ def _attempt_to_acquire_connection(self, status: RequestStatus) -> bool:
 
         # Otherwise create a new connection.
         connection = self.create_connection(origin)
+        trace(
+            "add_connection", logger, status.request, kwargs={"connection": connection}
+        )
         self._pool.insert(0, connection)
+        kwargs = {"request": status.request, "connection": connection}
+        trace("assign_request_to_connection", logger, status.request, kwargs)
         status.set_connection(connection)
         return True
 
@@ -192,6 +215,9 @@ def _close_expired_connections(self) -> None:
         for idx, connection in reversed(list(enumerate(self._pool))):
             if connection.has_expired():
                 connection.close()
+                trace(
+                    "remove_connection", logger, None, kwargs={"connection": connection}
+                )
                 self._pool.pop(idx)
 
         # If the pool size exceeds the maximum number of allowed keep-alive connections,
@@ -200,6 +226,9 @@ def _close_expired_connections(self) -> None:
         for idx, connection in reversed(list(enumerate(self._pool))):
             if connection.is_idle() and pool_size > self._max_keepalive_connections:
                 connection.close()
+                trace(
+                    "remove_connection", logger, None, kwargs={"connection": connection}
+                )
                 self._pool.pop(idx)
                 pool_size -= 1
 
@@ -222,6 +251,7 @@ def handle_request(self, request: Request) -> Response:
         status = RequestStatus(request)
 
         with self._pool_lock:
+            trace("add_request", logger, request, {"request": status.request})
             self._requests.append(status)
             self._close_expired_connections()
             self._attempt_to_acquire_connection(status)
@@ -235,9 +265,22 @@ def handle_request(self, request: Request) -> Response:
                 # If we timeout here, or if the task is cancelled, then make
                 # sure to remove the request from the queue before bubbling
                 # up the exception.
+                if isinstance(exc, httpcore.PoolTimeout):
+                    trace(
+                        "timeout_waiting_for_connection",
+                        logger,
+                        status.request,
+                        {"request": status.request},
+                    )
                 with self._pool_lock:
                     # Ensure only remove when task exists.
                     if status in self._requests:
+                        trace(
+                            "remove_request",
+                            logger,
+                            status.request,
+                            {"request": status.request},
+                        )
                         self._requests.remove(status)
                     raise exc
 
@@ -254,6 +297,13 @@ def handle_request(self, request: Request) -> Response:
                 with self._pool_lock:
                     # Maintain our position in the request queue, but reset the
                     # status so that the request becomes queued again.
+                    kwargs = {"request": status.request, "connection": connection}
+                    trace(
+                        "unassign_request_from_connection",
+                        logger,
+                        status.request,
+                        kwargs,
+                    )
                     status.unset_connection()
                     self._attempt_to_acquire_connection(status)
             except BaseException as exc:
@@ -285,6 +335,12 @@ def response_closed(self, status: RequestStatus) -> None:
         with self._pool_lock:
             # Update the state of the connection pool.
             if status in self._requests:
+                trace(
+                    "remove_request",
+                    logger,
+                    status.request,
+                    {"request": status.request},
+                )
                 self._requests.remove(status)
 
             if connection.is_closed() and connection in self._pool:
diff --git a/tests/_async/test_connection_pool.py b/tests/_async/test_connection_pool.py
index df0199ab..92367caf 100644
--- a/tests/_async/test_connection_pool.py
+++ b/tests/_async/test_connection_pool.py
@@ -136,6 +136,9 @@ async def trace(name, kwargs):
         await pool.request("GET", "https://example.com/", extensions={"trace": trace})
 
     assert called == [
+        "connection_pool.add_request",
+        "connection_pool.add_connection",
+        "connection_pool.assign_request_to_connection",
         "connection.connect_tcp.started",
         "connection.connect_tcp.complete",
         "connection.start_tls.started",
@@ -150,6 +153,7 @@ async def trace(name, kwargs):
         "http11.receive_response_body.complete",
         "http11.response_closed.started",
         "http11.response_closed.complete",
+        "connection_pool.remove_request",
     ]
 
 
@@ -175,49 +179,59 @@ async def test_debug_request(caplog):
         await pool.request("GET", "http://example.com/")
 
     assert caplog.record_tuples == [
+        ("httpcore.connection_pool", 10, "add_request request=<Request [b'GET']>"),
+        (
+            "httpcore.connection_pool",
+            10,
+            "add_connection connection=<AsyncHTTPConnection [CONNECTING]>",
+        ),
+        (
+            "httpcore.connection_pool",
+            10,
+            "assign_request_to_connection request=<Request [b'GET']> "
+            "connection=<AsyncHTTPConnection [CONNECTING]>",
+        ),
         (
             "httpcore.connection",
-            logging.DEBUG,
-            "connect_tcp.started host='example.com' port=80 local_address=None timeout=None socket_options=None",
+            10,
+            "connect_tcp.started host='example.com' port=80 local_address=None "
+            "timeout=None socket_options=None",
         ),
         (
             "httpcore.connection",
-            logging.DEBUG,
+            10,
             "connect_tcp.complete return_value=<httpcore.AsyncMockStream>",
         ),
         (
             "httpcore.http11",
-            logging.DEBUG,
+            10,
             "send_request_headers.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", logging.DEBUG, "send_request_headers.complete"),
-        (
-            "httpcore.http11",
-            logging.DEBUG,
-            "send_request_body.started request=<Request [b'GET']>",
-        ),
-        ("httpcore.http11", logging.DEBUG, "send_request_body.complete"),
+        ("httpcore.http11", 10, "send_request_headers.complete"),
+        ("httpcore.http11", 10, "send_request_body.started request=<Request [b'GET']>"),
+        ("httpcore.http11", 10, "send_request_body.complete"),
         (
             "httpcore.http11",
-            logging.DEBUG,
+            10,
             "receive_response_headers.started request=<Request [b'GET']>",
         ),
         (
             "httpcore.http11",
-            logging.DEBUG,
-            "receive_response_headers.complete return_value="
-            "(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'plain/text'), (b'Content-Length', b'13')])",
+            10,
+            "receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', "
+            "[(b'Content-Type', b'plain/text'), (b'Content-Length', b'13')])",
         ),
         (
             "httpcore.http11",
-            logging.DEBUG,
+            10,
             "receive_response_body.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", logging.DEBUG, "receive_response_body.complete"),
-        ("httpcore.http11", logging.DEBUG, "response_closed.started"),
-        ("httpcore.http11", logging.DEBUG, "response_closed.complete"),
-        ("httpcore.connection", logging.DEBUG, "close.started"),
-        ("httpcore.connection", logging.DEBUG, "close.complete"),
+        ("httpcore.http11", 10, "receive_response_body.complete"),
+        ("httpcore.http11", 10, "response_closed.started"),
+        ("httpcore.http11", 10, "response_closed.complete"),
+        ("httpcore.connection_pool", 10, "remove_request request=<Request [b'GET']>"),
+        ("httpcore.connection", 10, "close.started"),
+        ("httpcore.connection", 10, "close.complete"),
     ]
 
 
@@ -245,6 +259,9 @@ async def trace(name, kwargs):
         assert info == []
 
     assert called == [
+        "connection_pool.add_request",
+        "connection_pool.add_connection",
+        "connection_pool.assign_request_to_connection",
         "connection.connect_tcp.started",
         "connection.connect_tcp.complete",
         "connection.start_tls.started",
@@ -257,6 +274,7 @@ async def trace(name, kwargs):
         "http11.receive_response_headers.failed",
         "http11.response_closed.started",
         "http11.response_closed.complete",
+        "connection_pool.remove_request",
     ]
 
 
@@ -298,8 +316,12 @@ async def trace(name, kwargs):
         assert info == []
 
     assert called == [
+        "connection_pool.add_request",
+        "connection_pool.add_connection",
+        "connection_pool.assign_request_to_connection",
         "connection.connect_tcp.started",
         "connection.connect_tcp.failed",
+        "connection_pool.remove_request",
     ]
 
 
diff --git a/tests/_sync/test_connection_pool.py b/tests/_sync/test_connection_pool.py
index aafa68aa..eeec0479 100644
--- a/tests/_sync/test_connection_pool.py
+++ b/tests/_sync/test_connection_pool.py
@@ -136,6 +136,9 @@ def trace(name, kwargs):
         pool.request("GET", "https://example.com/", extensions={"trace": trace})
 
     assert called == [
+        "connection_pool.add_request",
+        "connection_pool.add_connection",
+        "connection_pool.assign_request_to_connection",
         "connection.connect_tcp.started",
         "connection.connect_tcp.complete",
         "connection.start_tls.started",
@@ -150,6 +153,7 @@ def trace(name, kwargs):
         "http11.receive_response_body.complete",
         "http11.response_closed.started",
         "http11.response_closed.complete",
+        "connection_pool.remove_request",
     ]
 
 
@@ -175,49 +179,59 @@ def test_debug_request(caplog):
         pool.request("GET", "http://example.com/")
 
     assert caplog.record_tuples == [
+        ("httpcore.connection_pool", 10, "add_request request=<Request [b'GET']>"),
+        (
+            "httpcore.connection_pool",
+            10,
+            "add_connection connection=<HTTPConnection [CONNECTING]>",
+        ),
+        (
+            "httpcore.connection_pool",
+            10,
+            "assign_request_to_connection request=<Request [b'GET']> "
+            "connection=<HTTPConnection [CONNECTING]>",
+        ),
         (
             "httpcore.connection",
-            logging.DEBUG,
-            "connect_tcp.started host='example.com' port=80 local_address=None timeout=None socket_options=None",
+            10,
+            "connect_tcp.started host='example.com' port=80 local_address=None "
+            "timeout=None socket_options=None",
         ),
         (
             "httpcore.connection",
-            logging.DEBUG,
+            10,
             "connect_tcp.complete return_value=<httpcore.MockStream>",
         ),
         (
             "httpcore.http11",
-            logging.DEBUG,
+            10,
             "send_request_headers.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", logging.DEBUG, "send_request_headers.complete"),
-        (
-            "httpcore.http11",
-            logging.DEBUG,
-            "send_request_body.started request=<Request [b'GET']>",
-        ),
-        ("httpcore.http11", logging.DEBUG, "send_request_body.complete"),
+        ("httpcore.http11", 10, "send_request_headers.complete"),
+        ("httpcore.http11", 10, "send_request_body.started request=<Request [b'GET']>"),
+        ("httpcore.http11", 10, "send_request_body.complete"),
         (
             "httpcore.http11",
-            logging.DEBUG,
+            10,
             "receive_response_headers.started request=<Request [b'GET']>",
         ),
         (
             "httpcore.http11",
-            logging.DEBUG,
-            "receive_response_headers.complete return_value="
-            "(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'plain/text'), (b'Content-Length', b'13')])",
+            10,
+            "receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', "
+            "[(b'Content-Type', b'plain/text'), (b'Content-Length', b'13')])",
         ),
         (
             "httpcore.http11",
-            logging.DEBUG,
+            10,
             "receive_response_body.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", logging.DEBUG, "receive_response_body.complete"),
-        ("httpcore.http11", logging.DEBUG, "response_closed.started"),
-        ("httpcore.http11", logging.DEBUG, "response_closed.complete"),
-        ("httpcore.connection", logging.DEBUG, "close.started"),
-        ("httpcore.connection", logging.DEBUG, "close.complete"),
+        ("httpcore.http11", 10, "receive_response_body.complete"),
+        ("httpcore.http11", 10, "response_closed.started"),
+        ("httpcore.http11", 10, "response_closed.complete"),
+        ("httpcore.connection_pool", 10, "remove_request request=<Request [b'GET']>"),
+        ("httpcore.connection", 10, "close.started"),
+        ("httpcore.connection", 10, "close.complete"),
     ]
 
 
@@ -245,6 +259,9 @@ def trace(name, kwargs):
         assert info == []
 
     assert called == [
+        "connection_pool.add_request",
+        "connection_pool.add_connection",
+        "connection_pool.assign_request_to_connection",
         "connection.connect_tcp.started",
         "connection.connect_tcp.complete",
         "connection.start_tls.started",
@@ -257,6 +274,7 @@ def trace(name, kwargs):
         "http11.receive_response_headers.failed",
         "http11.response_closed.started",
         "http11.response_closed.complete",
+        "connection_pool.remove_request",
     ]
 
 
@@ -298,8 +316,12 @@ def trace(name, kwargs):
         assert info == []
 
     assert called == [
+        "connection_pool.add_request",
+        "connection_pool.add_connection",
+        "connection_pool.assign_request_to_connection",
         "connection.connect_tcp.started",
         "connection.connect_tcp.failed",
+        "connection_pool.remove_request",
     ]
 
 
diff --git a/unasync.py b/unasync.py
index d3607cd4..597a1112 100755
--- a/unasync.py
+++ b/unasync.py
@@ -27,6 +27,7 @@
     ('@pytest.mark.anyio', ''),
     ('@pytest.mark.trio', ''),
     ('AutoBackend', 'SyncBackend'),
+    ('atrace', 'trace'),
 ]
 COMPILED_SUBS = [
     (re.compile(r'(^|\b)' + regex + r'($|\b)'), repl)

From ff05c832ff1cd1b3f96e92c98f4a030e405a814d Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Sat, 10 Jun 2023 10:12:03 +0300
Subject: [PATCH 3/8] Add forgotten remove_connection log

---
 httpcore/_async/connection_pool.py | 6 ++++++
 httpcore/_sync/connection_pool.py  | 6 ++++++
 2 files changed, 12 insertions(+)

diff --git a/httpcore/_async/connection_pool.py b/httpcore/_async/connection_pool.py
index fee6c695..60954228 100644
--- a/httpcore/_async/connection_pool.py
+++ b/httpcore/_async/connection_pool.py
@@ -344,6 +344,12 @@ async def response_closed(self, status: RequestStatus) -> None:
                 self._requests.remove(status)
 
             if connection.is_closed() and connection in self._pool:
+                await atrace(
+                    "remove_connection",
+                    logger,
+                    None,
+                    kwargs={"connection": connection},
+                )
                 self._pool.remove(connection)
 
             # Since we've had a response closed, it's possible we'll now be able
diff --git a/httpcore/_sync/connection_pool.py b/httpcore/_sync/connection_pool.py
index 43f7d732..199d1a43 100644
--- a/httpcore/_sync/connection_pool.py
+++ b/httpcore/_sync/connection_pool.py
@@ -344,6 +344,12 @@ def response_closed(self, status: RequestStatus) -> None:
                 self._requests.remove(status)
 
             if connection.is_closed() and connection in self._pool:
+                trace(
+                    "remove_connection",
+                    logger,
+                    None,
+                    kwargs={"connection": connection},
+                )
                 self._pool.remove(connection)
 
             # Since we've had a response closed, it's possible we'll now be able

From 3f1828859aee22bc4aab97664273cc01f4106cd6 Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Sat, 10 Jun 2023 11:44:55 +0300
Subject: [PATCH 4/8] update docs

---
 docs/extensions.md | 12 ++++++++++++
 1 file changed, 12 insertions(+)

diff --git a/docs/extensions.md b/docs/extensions.md
index 3ac3d082..3193d518 100644
--- a/docs/extensions.md
+++ b/docs/extensions.md
@@ -119,6 +119,8 @@ The `event_name` and `info` arguments here will be one of the following:
 * `{event_type}.{event_name}.started`, `<dictionary of keyword arguments>`
 * `{event_type}.{event_name}.complete`, `{"return_value": <...>}`
 * `{event_type}.{event_name}.failed`, `{"exception": <...>}`
+* `{event_type}.{event_name}`, `<dictionary of keyword arguments>`
+
 
 Note that when using the async variant of `httpcore` the handler function passed to `"trace"` must be an `async def ...` function.
 
@@ -130,6 +132,15 @@ The following event types are currently exposed...
 * `"connection.connect_unix_socket"`
 * `"connection.start_tls"`
 
+**Connection pool events**
+* `"connection_pool.add_request"`
+* `"connection_pool.remove_request"`
+* `"connection_pool.add_connection"`
+* `"connection_pool.reuse_connection"`
+* `"connection_pool.assign_request_to_connection"`
+* `"connection_pool.unassign_request_from_connection"`
+* `"connection_pool.timeout_waiting_for_connection"`
+
 **HTTP/1.1 events**
 
 * `"http11.send_request_headers"`
@@ -147,6 +158,7 @@ The following event types are currently exposed...
 * `"http2.receive_response_body"`
 * `"http2.response_closed"`
 
+
 ### `"sni_hostname"`
 
 The server's hostname, which is used to confirm the hostname supplied by the SSL certificate.

From a96a826a6791ddb0ce5f8fcb1e44996c21ce3e82 Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Mon, 12 Jun 2023 08:22:40 +0300
Subject: [PATCH 5/8] update changelog

---
 CHANGELOG.md | 1 +
 1 file changed, 1 insertion(+)

diff --git a/CHANGELOG.md b/CHANGELOG.md
index d2abd040..12000381 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -7,6 +7,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/).
 ## unreleased
 
 - The networking backend interface has [been added to the public API](https://www.encode.io/httpcore/network-backends). Some classes which were previously private implementation detail are now part of the top-level public API. (#699)
+- Add some connection pool events for trace extension. (#702)
 
 ## 0.17.2 (May 23th, 2023)
 

From efaaea5bc5b5fa7f4f9cfb00462fd4fedf9bcdb9 Mon Sep 17 00:00:00 2001
From: Karen Petrosyan <92274156+karosis88@users.noreply.github.com>
Date: Mon, 12 Jun 2023 15:45:36 +0300
Subject: [PATCH 6/8] Update docs/extensions.md

Co-authored-by: Tom Christie <tom@tomchristie.com>
---
 docs/extensions.md | 1 +
 1 file changed, 1 insertion(+)

diff --git a/docs/extensions.md b/docs/extensions.md
index 3193d518..630a6a20 100644
--- a/docs/extensions.md
+++ b/docs/extensions.md
@@ -133,6 +133,7 @@ The following event types are currently exposed...
 * `"connection.start_tls"`
 
 **Connection pool events**
+
 * `"connection_pool.add_request"`
 * `"connection_pool.remove_request"`
 * `"connection_pool.add_connection"`

From 6c0ce0cfa073d32c0ae79e84df6c4dd36221c0f5 Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Mon, 12 Jun 2023 15:57:05 +0300
Subject: [PATCH 7/8] Some refactoring

---
 docs/extensions.md                 | 2 --
 httpcore/_async/connection_pool.py | 6 ++----
 httpcore/_sync/connection_pool.py  | 6 ++----
 3 files changed, 4 insertions(+), 10 deletions(-)

diff --git a/docs/extensions.md b/docs/extensions.md
index 3193d518..81a0ba6f 100644
--- a/docs/extensions.md
+++ b/docs/extensions.md
@@ -121,7 +121,6 @@ The `event_name` and `info` arguments here will be one of the following:
 * `{event_type}.{event_name}.failed`, `{"exception": <...>}`
 * `{event_type}.{event_name}`, `<dictionary of keyword arguments>`
 
-
 Note that when using the async variant of `httpcore` the handler function passed to `"trace"` must be an `async def ...` function.
 
 The following event types are currently exposed...
@@ -158,7 +157,6 @@ The following event types are currently exposed...
 * `"http2.receive_response_body"`
 * `"http2.response_closed"`
 
-
 ### `"sni_hostname"`
 
 The server's hostname, which is used to confirm the hostname supplied by the SSL certificate.
diff --git a/httpcore/_async/connection_pool.py b/httpcore/_async/connection_pool.py
index 60954228..e44e49d8 100644
--- a/httpcore/_async/connection_pool.py
+++ b/httpcore/_async/connection_pool.py
@@ -4,11 +4,9 @@
 from types import TracebackType
 from typing import AsyncIterable, AsyncIterator, Iterable, List, Optional, Type
 
-import httpcore
-
 from .._backends.auto import AutoBackend
 from .._backends.base import SOCKET_OPTION, AsyncNetworkBackend
-from .._exceptions import ConnectionNotAvailable, UnsupportedProtocol
+from .._exceptions import ConnectionNotAvailable, PoolTimeout, UnsupportedProtocol
 from .._models import Origin, Request, Response
 from .._synchronization import AsyncEvent, AsyncLock
 from .._trace import atrace
@@ -265,7 +263,7 @@ async def handle_async_request(self, request: Request) -> Response:
                 # If we timeout here, or if the task is cancelled, then make
                 # sure to remove the request from the queue before bubbling
                 # up the exception.
-                if isinstance(exc, httpcore.PoolTimeout):
+                if isinstance(exc, PoolTimeout):
                     await atrace(
                         "timeout_waiting_for_connection",
                         logger,
diff --git a/httpcore/_sync/connection_pool.py b/httpcore/_sync/connection_pool.py
index 199d1a43..91766900 100644
--- a/httpcore/_sync/connection_pool.py
+++ b/httpcore/_sync/connection_pool.py
@@ -4,11 +4,9 @@
 from types import TracebackType
 from typing import Iterable, Iterator, Iterable, List, Optional, Type
 
-import httpcore
-
 from .._backends.sync import SyncBackend
 from .._backends.base import SOCKET_OPTION, NetworkBackend
-from .._exceptions import ConnectionNotAvailable, UnsupportedProtocol
+from .._exceptions import ConnectionNotAvailable, PoolTimeout, UnsupportedProtocol
 from .._models import Origin, Request, Response
 from .._synchronization import Event, Lock
 from .._trace import trace
@@ -265,7 +263,7 @@ def handle_request(self, request: Request) -> Response:
                 # If we timeout here, or if the task is cancelled, then make
                 # sure to remove the request from the queue before bubbling
                 # up the exception.
-                if isinstance(exc, httpcore.PoolTimeout):
+                if isinstance(exc, PoolTimeout):
                     trace(
                         "timeout_waiting_for_connection",
                         logger,

From d47c45dd2e7208a47bc27cb91ad294013c4c943b Mon Sep 17 00:00:00 2001
From: karosis88 <kar.petrosyanpy@gmail.com>
Date: Tue, 13 Jun 2023 09:14:57 +0300
Subject: [PATCH 8/8] Change 10 to logging.DEBUG

---
 tests/_async/test_connection_pool.py | 48 +++++++++++++++++-----------
 tests/_sync/test_connection_pool.py  | 48 +++++++++++++++++-----------
 2 files changed, 60 insertions(+), 36 deletions(-)

diff --git a/tests/_async/test_connection_pool.py b/tests/_async/test_connection_pool.py
index 92367caf..c8a660fe 100644
--- a/tests/_async/test_connection_pool.py
+++ b/tests/_async/test_connection_pool.py
@@ -179,59 +179,71 @@ async def test_debug_request(caplog):
         await pool.request("GET", "http://example.com/")
 
     assert caplog.record_tuples == [
-        ("httpcore.connection_pool", 10, "add_request request=<Request [b'GET']>"),
         (
             "httpcore.connection_pool",
-            10,
+            logging.DEBUG,
+            "add_request request=<Request [b'GET']>",
+        ),
+        (
+            "httpcore.connection_pool",
+            logging.DEBUG,
             "add_connection connection=<AsyncHTTPConnection [CONNECTING]>",
         ),
         (
             "httpcore.connection_pool",
-            10,
+            logging.DEBUG,
             "assign_request_to_connection request=<Request [b'GET']> "
             "connection=<AsyncHTTPConnection [CONNECTING]>",
         ),
         (
             "httpcore.connection",
-            10,
+            logging.DEBUG,
             "connect_tcp.started host='example.com' port=80 local_address=None "
             "timeout=None socket_options=None",
         ),
         (
             "httpcore.connection",
-            10,
+            logging.DEBUG,
             "connect_tcp.complete return_value=<httpcore.AsyncMockStream>",
         ),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
             "send_request_headers.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", 10, "send_request_headers.complete"),
-        ("httpcore.http11", 10, "send_request_body.started request=<Request [b'GET']>"),
-        ("httpcore.http11", 10, "send_request_body.complete"),
+        ("httpcore.http11", logging.DEBUG, "send_request_headers.complete"),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
+            "send_request_body.started request=<Request [b'GET']>",
+        ),
+        ("httpcore.http11", logging.DEBUG, "send_request_body.complete"),
+        (
+            "httpcore.http11",
+            logging.DEBUG,
             "receive_response_headers.started request=<Request [b'GET']>",
         ),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
             "receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', "
             "[(b'Content-Type', b'plain/text'), (b'Content-Length', b'13')])",
         ),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
             "receive_response_body.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", 10, "receive_response_body.complete"),
-        ("httpcore.http11", 10, "response_closed.started"),
-        ("httpcore.http11", 10, "response_closed.complete"),
-        ("httpcore.connection_pool", 10, "remove_request request=<Request [b'GET']>"),
-        ("httpcore.connection", 10, "close.started"),
-        ("httpcore.connection", 10, "close.complete"),
+        ("httpcore.http11", logging.DEBUG, "receive_response_body.complete"),
+        ("httpcore.http11", logging.DEBUG, "response_closed.started"),
+        ("httpcore.http11", logging.DEBUG, "response_closed.complete"),
+        (
+            "httpcore.connection_pool",
+            logging.DEBUG,
+            "remove_request request=<Request [b'GET']>",
+        ),
+        ("httpcore.connection", logging.DEBUG, "close.started"),
+        ("httpcore.connection", logging.DEBUG, "close.complete"),
     ]
 
 
diff --git a/tests/_sync/test_connection_pool.py b/tests/_sync/test_connection_pool.py
index eeec0479..63cd7144 100644
--- a/tests/_sync/test_connection_pool.py
+++ b/tests/_sync/test_connection_pool.py
@@ -179,59 +179,71 @@ def test_debug_request(caplog):
         pool.request("GET", "http://example.com/")
 
     assert caplog.record_tuples == [
-        ("httpcore.connection_pool", 10, "add_request request=<Request [b'GET']>"),
         (
             "httpcore.connection_pool",
-            10,
+            logging.DEBUG,
+            "add_request request=<Request [b'GET']>",
+        ),
+        (
+            "httpcore.connection_pool",
+            logging.DEBUG,
             "add_connection connection=<HTTPConnection [CONNECTING]>",
         ),
         (
             "httpcore.connection_pool",
-            10,
+            logging.DEBUG,
             "assign_request_to_connection request=<Request [b'GET']> "
             "connection=<HTTPConnection [CONNECTING]>",
         ),
         (
             "httpcore.connection",
-            10,
+            logging.DEBUG,
             "connect_tcp.started host='example.com' port=80 local_address=None "
             "timeout=None socket_options=None",
         ),
         (
             "httpcore.connection",
-            10,
+            logging.DEBUG,
             "connect_tcp.complete return_value=<httpcore.MockStream>",
         ),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
             "send_request_headers.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", 10, "send_request_headers.complete"),
-        ("httpcore.http11", 10, "send_request_body.started request=<Request [b'GET']>"),
-        ("httpcore.http11", 10, "send_request_body.complete"),
+        ("httpcore.http11", logging.DEBUG, "send_request_headers.complete"),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
+            "send_request_body.started request=<Request [b'GET']>",
+        ),
+        ("httpcore.http11", logging.DEBUG, "send_request_body.complete"),
+        (
+            "httpcore.http11",
+            logging.DEBUG,
             "receive_response_headers.started request=<Request [b'GET']>",
         ),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
             "receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', "
             "[(b'Content-Type', b'plain/text'), (b'Content-Length', b'13')])",
         ),
         (
             "httpcore.http11",
-            10,
+            logging.DEBUG,
             "receive_response_body.started request=<Request [b'GET']>",
         ),
-        ("httpcore.http11", 10, "receive_response_body.complete"),
-        ("httpcore.http11", 10, "response_closed.started"),
-        ("httpcore.http11", 10, "response_closed.complete"),
-        ("httpcore.connection_pool", 10, "remove_request request=<Request [b'GET']>"),
-        ("httpcore.connection", 10, "close.started"),
-        ("httpcore.connection", 10, "close.complete"),
+        ("httpcore.http11", logging.DEBUG, "receive_response_body.complete"),
+        ("httpcore.http11", logging.DEBUG, "response_closed.started"),
+        ("httpcore.http11", logging.DEBUG, "response_closed.complete"),
+        (
+            "httpcore.connection_pool",
+            logging.DEBUG,
+            "remove_request request=<Request [b'GET']>",
+        ),
+        ("httpcore.connection", logging.DEBUG, "close.started"),
+        ("httpcore.connection", logging.DEBUG, "close.complete"),
     ]