chore(sdk): Log the pos and the timeout as part of the sync_once span.

This patch adds the `pos` and `timeout` value as new fields of the
`sync_once` span.

How to test it?

```sh
$ cargo nextest run --retries 0 --no-fail-fast -E "not test(ensure_no_max_concurrent)" -p matrix-sdk-ui --nocapture -- test_sync_all_states | rg sync_once
2026-02-04T14:02:17.043301Z DEBUG sync_once{conn_id="room-list" pos="0" timeout=0}:send{request_id="REQ-3" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="647B" status=200 response_size="72B" request_duration=316.959µs}: matrix_sdk::http_client: Got response
2026-02-04T14:02:17.043783Z DEBUG sync_once{conn_id="room-list" pos="1" timeout=0}:send{request_id="REQ-4" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="648B"}: matrix_sdk::http_client::native: Sending request num_attempt=1
2026-02-04T14:02:17.044093Z DEBUG sync_once{conn_id="room-list" pos="1" timeout=0}:send{request_id="REQ-4" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="648B" status=200 response_size="72B" request_duration=283.75µs}: matrix_sdk::http_client: Got response
2026-02-04T14:02:17.044527Z DEBUG sync_once{conn_id="room-list" pos="2" timeout=0}:send{request_id="REQ-5" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="648B"}: matrix_sdk::http_client::native: Sending request num_attempt=1
2026-02-04T14:02:17.044808Z DEBUG sync_once{conn_id="room-list" pos="2" timeout=0}:send{request_id="REQ-5" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="648B" status=200 response_size="72B" request_duration=254.875µs}: matrix_sdk::http_client: Got response
2026-02-04T14:02:17.045245Z DEBUG sync_once{conn_id="room-list" pos="3" timeout=30000}:send{request_id="REQ-6" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="648B"}: matrix_sdk::http_client::native: Sending request num_attempt=1
2026-02-04T14:02:17.045517Z DEBUG sync_once{conn_id="room-list" pos="3" timeout=30000}:send{request_id="REQ-6" method=POST uri="http://127.0.0.1:49663/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="648B" status=200 response_size="72B" request_duration=247.417µs}: matrix_sdk::http_client: Got response
```
This commit is contained in:
Ivan Enderlin
2026-02-04 15:03:47 +01:00
parent f3b9a01904
commit 52014dc0bb
2 changed files with 9 additions and 4 deletions
+4
View File
@@ -179,10 +179,14 @@ impl HttpClient {
let method = request.method();
let mut uri_parts = request.uri().clone().into_parts();
// Erase the query parameters for the sake of secrecy (in case a token is
// present).
if let Some(path_and_query) = &mut uri_parts.path_and_query {
*path_and_query =
path_and_query.path().try_into().expect("path is valid PathAndQuery");
}
let uri = http::Uri::from_parts(uri_parts).expect("created from valid URI");
span.record("method", debug(method)).record("uri", uri.to_string());
+5 -4
View File
@@ -400,7 +400,6 @@ impl SlidingSync {
Ok(update_summary)
}
#[instrument(skip_all)]
async fn generate_sync_request(
&self,
) -> Result<(http::Request, RequestConfig, OwnedMutexGuard<SlidingSyncPositionMarkers>)> {
@@ -467,8 +466,6 @@ impl SlidingSync {
position_guard.pos.clone()
};
Span::current().record("pos", &pos);
// When the client sends a request with no `pos`, MSC4186 returns no device
// lists updates, as it only returns changes since the provided `pos`
// (which is `null` in this case); this is in line with sync v2.
@@ -496,6 +493,10 @@ impl SlidingSync {
PollTimeout::Default => Some(self.inner.poll_timeout),
};
Span::current()
.record("pos", &pos)
.record("timeout", timeout.map(|duration| duration.as_millis()));
let mut request = assign!(http::Request::new(), {
conn_id: Some(self.inner.id.clone()),
pos,
@@ -672,7 +673,7 @@ impl SlidingSync {
///
/// Public for testing purposes only.
#[doc(hidden)]
#[instrument(skip_all, fields(pos, conn_id = self.inner.id))]
#[instrument(skip_all, fields(conn_id = self.inner.id, pos, timeout))]
pub async fn sync_once(&self) -> Result<UpdateSummary> {
let (request, request_config, position_guard) = self.generate_sync_request().await?;