Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Reduce volume of 'Waiting for current token' logs, which were introduced in v1.109.0. #17428

Merged
merged 3 commits into from
Jul 23, 2024
Merged

Reduce volume of 'Waiting for current token' logs, which were introduced in v1.109.0. #17428

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
3353d35
Only log once when waiting for current token to catch up
reivilibre Jul 9, 2024
0062c9e
Newsfile
reivilibre Jul 9, 2024
ac7ebb8
Use shorter formatting for StreamToken
reivilibre Jul 10, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/17428.bugfix
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Reduce volume of 'Waiting for current token' logs, which were introduced in v1.109.0.
13 changes: 8 additions & 5 deletions synapse/notifier.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -773,6 +773,7 @@ async def wait_for_stream_token(self, stream_token: StreamToken) -> bool:
stream_token = await self.event_sources.bound_future_token(stream_token)

start = self.clock.time_msec()
logged = False
while True:
current_token = self.event_sources.get_current_token()
if stream_token.is_before_or_eq(current_token):
Expand All @@ -783,11 +784,13 @@ async def wait_for_stream_token(self, stream_token: StreamToken) -> bool:
if now - start > 10_000:
return False

logger.info(
"Waiting for current token to reach %s; currently at %s",
stream_token,
current_token,
)
if not logged:
logger.info(
"Waiting for current token to reach %s; currently at %s",
stream_token,
current_token,
)
logged = True

# TODO: be better
await self.clock.sleep(0.5)
Expand Down
23 changes: 23 additions & 0 deletions synapse/types/__init__.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -740,6 +740,13 @@ def bound_stream_token(self, max_stream: int) -> "RoomStreamToken":

return super().bound_stream_token(max_stream)

def __str__(self) -> str:
instances = ", ".join(f"{k}: {v}" for k, v in sorted(self.instance_map.items()))
return (
f"RoomStreamToken(stream: {self.stream}, topological: {self.topological}, "
f"instances: {{{instances}}})"
)


@attr.s(frozen=True, slots=True, order=False)
class MultiWriterStreamToken(AbstractMultiWriterStreamToken):
Expand Down Expand Up @@ -824,6 +831,13 @@ def is_stream_position_in_range(

return True

def __str__(self) -> str:
instances = ", ".join(f"{k}: {v}" for k, v in sorted(self.instance_map.items()))
return (
f"MultiWriterStreamToken(stream: {self.stream}, "
f"instances: {{{instances}}})"
)


class StreamKeyType(Enum):
"""Known stream types.
Expand Down Expand Up @@ -1082,6 +1096,15 @@ def is_before_or_eq(self, other_token: "StreamToken") -> bool:

return True

def __str__(self) -> str:
return (
f"StreamToken(room: {self.room_key}, presence: {self.presence_key}, "
f"typing: {self.typing_key}, receipt: {self.receipt_key}, "
f"account_data: {self.account_data_key}, push_rules: {self.push_rules_key}, "
f"to_device: {self.to_device_key}, device_list: {self.device_list_key}, "
f"groups: {self.groups_key}, un_partial_stated_rooms: {self.un_partial_stated_rooms_key})"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is this a better representation than the default? Isn't this just replace e.g. presence=5 with presence: 5?

Copy link
Contributor Author

@reivilibre reivilibre Jul 16, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

2 things to cut down on the noise:

  • removes _token suffix on all the fields
  • better formatting for the dict, which by default is immutabledict({..}). I don't tend to care that it's immutable when I'm reading the logs

)


StreamToken.START = StreamToken(
RoomStreamToken(stream=0), 0, 0, MultiWriterStreamToken(stream=0), 0, 0, 0, 0, 0, 0
Expand Down
Loading