Add log to determine whether clients are using /messages as expected
#19226
Conversation
| # Useful for debugging timeline/pagination issues. For example, if a client | ||
| # isn't seeing the full history, we can check the homeserver logs to see if the | ||
| # client just never made the next request with the given `end` token. | ||
| logger.info( | ||
| "Responding to `/messages` request: {%s} %s %s -> %d messages with end_token=%s", | ||
| requester.user.to_string(), | ||
| request.get_method(), | ||
| request.get_redacted_uri(), | ||
| len(get_messages_result.messages_chunk), | ||
| (await get_messages_result.end_token.to_string(self.store)) | ||
| if get_messages_result.end_token | ||
| else None, | ||
| ) |
There was a problem hiding this comment.
This is the main objective of this PR.
The rest is just refactoring for better types and separation of concerns so we can pull it out easier instead of shoddy JSON dict lookups.
| # Useful for debugging timeline/pagination issues. For example, if a client | ||
| # isn't seeing the full history, we can check the homeserver logs to see if the | ||
| # client just never made the next request with the given `end` token. | ||
| logger.info( |
There was a problem hiding this comment.
Using logger.info(...) as it's at the same logging level as our access logs:
synapse.access.http.8080 - 521 - INFO - GET-9 - ::ffff:127.0.0.1 - 8080 - {@user-2-bob:hs2} Processed request: 1.535sec/0.000sec (0.019sec, 0.001sec) (0.086sec/0.076sec/135) 861B 200 "GET /_matrix/client/r0/rooms/%21zCWZKZWGiStxkXpoSZ:hs1/messages?dir=b&limit=10 HTTP/1.0" "Go-http-client/1.1" [4 dbevts]
| state, time_now, config=serialize_options | ||
| ) | ||
|
|
||
| return chunk |
There was a problem hiding this comment.
Better separation of concerns. We now do the serializing/encoding at the REST layer instead of in the handler (see encode_messages_response)
reivilibre
left a comment
reivilibre
left a comment
There was a problem hiding this comment.
can't argue with any of that, nice cleanup :)
| requester.user.to_string(), | ||
| request.get_method(), | ||
| request.get_redacted_uri(), |
There was a problem hiding this comment.
are these fields useful, given they would be visible in the same logcontext?
(Don't mind either way)
| """ | ||
| A list of state events relevant to showing the chunk. For example, if | ||
| lazy_load_members is enabled in the filter then this may contain the membership | ||
| events for the senders of events in the chunk. | ||
| """ |
There was a problem hiding this comment.
nit: we should also state that this field is omitted from the response if it's none, as we do with end_token.
And perhaps especially note that empty lists will be omitted as well.
Add log to determine whether clients are using
/messagesas expectedSpawning from wanting some better homeserver logs to debug #19153. We can check whether we are returning a
/messagesresponse with anendpagination token and then check to see whether the client is making another/messagesrequest with that token.Although clients should also have similar logs and debugging capabilities to determine this info as well. This just makes it easier for us when someone creates an issue claiming backend issue and we can ask them for homeserver logs.
Dev notes
Pull Request Checklist
EventStoretoEventWorkerStore.".code blocks.