Solving the race conditions for logging #3855

bcdurak · 2025-07-18T15:07:33Z

Describe changes

I implemented/fixed _ to achieve _.

Pre-requisites

Please ensure you have done the following:

I have read the CONTRIBUTING.md document.
I have added tests to cover my changes.
I have based my new branch on develop and the open PR is targeting develop. If your branch wasn't based on develop read Contribution guide on rebasing branch to develop.
IMPORTANT: I made sure that my changes are reflected properly in the following resources:
- ZenML Docs
- Dashboard: Needs to be communicated to the frontend team.
- Templates: Might need adjustments (that are not reflected in the template tests) in case of non-breaking changes and deprecations.
- Projects: Depending on the version dependencies, different projects might get affected.

Types of changes

Bug fix (non-breaking change which fixes an issue)
New feature (non-breaking change which adds functionality)
Breaking change (fix or feature that would cause existing functionality to change)
Other (add details above)

coderabbitai · 2025-07-18T15:07:39Z

Important

Review skipped

Auto reviews are disabled on this repository.

Please check the settings in the CodeRabbit UI or the .coderabbit.yaml file in this repository. To trigger a single review, invoke the @coderabbitai review command.

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

✨ Finishing Touches

🧪 Generate unit tests

Create PR with unit tests
Post copyable unit tests in a comment
Commit unit tests in branch bugfix/gcsfs-log-interactions

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

🪧 Tips

Chat

There are 3 ways to chat with CodeRabbit:

Review comments: Directly reply to a review comment made by CodeRabbit. Example:
- I pushed a fix in commit <commit_id>, please review it.
- Explain this complex logic.
- Open a follow-up GitHub issue for this discussion.
Files and specific lines of code (under the "Files changed" tab): Tag @coderabbitai in a new review comment at the desired location with your query. Examples:
- @coderabbitai explain this code block.
- @coderabbitai modularize this function.
PR comments: Tag @coderabbitai in a new PR comment to ask questions about the PR branch. For the best results, please provide a very specific query, as very limited context is provided in this mode. Examples:
- @coderabbitai gather interesting stats about this repository and render them as a table. Additionally, render a pie chart showing the language distribution in the codebase.
- @coderabbitai read src/utils.ts and explain its main purpose.
- @coderabbitai read the files in the src/scheduler package and generate a class diagram using mermaid and a README in the markdown format.
- @coderabbitai help me debug CodeRabbit configuration file.

Support

Need help? Create a ticket on our support page for assistance with any issues or questions.

Note: Be mindful of the bot's finite context window. It's strongly recommended to break down tasks such as reading entire modules into smaller chunks. For a focused discussion, use review comments to chat about specific files and their changes, instead of using the PR comments.

CodeRabbit Commands (Invoked using PR comments)

@coderabbitai pause to pause the reviews on a PR.
@coderabbitai resume to resume the paused reviews.
@coderabbitai review to trigger an incremental review. This is useful when automatic reviews are disabled for the repository.
@coderabbitai full review to do a full review from scratch and review all the files again.
@coderabbitai summary to regenerate the summary of the PR.
@coderabbitai generate docstrings to generate docstrings for this PR.
@coderabbitai generate sequence diagram to generate a sequence diagram of the changes in this PR.
@coderabbitai generate unit tests to generate unit tests for this PR.
@coderabbitai resolve resolve all the CodeRabbit review comments.
@coderabbitai configuration to show the current CodeRabbit configuration for the repository.
@coderabbitai help to get help.

Other keywords and placeholders

Add @coderabbitai ignore anywhere in the PR description to prevent this PR from being reviewed.
Add @coderabbitai summary to generate the high-level summary at a specific location in the PR description.
Add @coderabbitai anywhere in the PR title to generate the title automatically.

Documentation and Community

Visit our Documentation for detailed information on how to use CodeRabbit.
Join our Discord Community to get help, request features, and share feedback.
Follow us on X/Twitter for updates and announcements.

src/zenml/logging/step_logging.py

schustmi

@bcdurak Did you by any chance run some tests to see if this slows down the logging in any considerable way?

bcdurak · 2025-07-21T15:05:10Z

@schustmi I am running the stress test now. Will merge if everything is in the green.

schustmi

In general this is written in a way that makes it very hard to grasp what is happening, as there is so much locking happening in so many places.

Wouldn't it be much simpler like this? Obviously very simplified:

def write(...):
  buffer_to_write = []
  
  with self.buffer_lock:
    self.buffer.append(...)
    if self.should_write():
      buffer_to_write = self.buffer.copy()
      self.buffer = []
      self.last_merge_time = time.time()
  
  if buffer_to_write:
    self._write_data(buffer_to_write)

And then have the io_lock in _write_data? Of course we would still need to make sure the threads enter the io_lock in the correct order, and this doesn't cover the merging yet. But I feel like it would be much clearer, wdyt?

src/zenml/logging/step_logging.py

bcdurak · 2025-07-23T18:34:27Z

In general this is written in a way that makes it very hard to grasp what is happening, as there is so much locking happening in so many places.

Wouldn't it be much simpler like this? Obviously very simplified:
def write(...):
  buffer_to_write = []
  
  with self.buffer_lock:
    self.buffer.append(...)
    if self.should_write():
      buffer_to_write = self.buffer.copy()
      self.buffer = []
      self.last_merge_time = time.time()
  
  if buffer_to_write:
    self._write_data(buffer_to_write)
And then have the io_lock in _write_data? Of course we would still need to make sure the threads enter the io_lock in the correct order, and this doesn't cover the merging yet. But I feel like it would be much clearer, wdyt?

Exactly what I have been struggling with. This way, it would have been much simpler but you pointed out the main problem. If there are two threads that finishes the buffer process (and they want to write the buffer to the file), it is possible for the for the order to get messed up. I am trying a solution where the process picks up the io_lock right before releasing the buffer_lock (if they need to merge or write). So far, it seems to work but performance-wise it wasn't that different from using a single lock.

While I was playing around with it, I have discovered other problems as well:

We protect our system against any logs that happen during the save_to_file call but we do not currently protect it during the write call and the merge calls (I guess it is very unlikely for the merge to recursively call itself).
Additionally, (and also more importantly) if we separate the locks, the io_lock would currently set the self.disabled to True (because we don't want to deal with any log messages coming from the artifact store implementations). However, while the IO operations are happening within the thread that acquired the io_lock, it would make the other threads unable to use the write functionality of the storage instance because it's disabled.

bcdurak · 2025-07-23T18:40:25Z

@schustmi I have pushed the idea that I had in mind. The code is still in a bit of a dirty state, but feel free to take a look.

bcdurak · 2025-07-25T14:56:16Z

@schustmi, I revamped the whole thing. Feel free to take a look.

src/zenml/integrations/aws/step_operators/sagemaker_step_operator.py

src/zenml/logging/__init__.py

src/zenml/orchestrators/step_launcher.py

src/zenml/logging/step_logging.py

bcdurak added 2 commits July 18, 2025 17:03

lock

2141c86

formatting

2f98309

github-actions bot added internal To filter out internal PRs and issues bug Something isn't working labels Jul 18, 2025

schustmi requested changes Jul 21, 2025

View reviewed changes

src/zenml/logging/step_logging.py Outdated Show resolved Hide resolved

bcdurak added 2 commits July 21, 2025 14:09

switching to rlock

b2bdc5f

merged develop

5e184cd

bcdurak requested a review from schustmi July 21, 2025 12:10

bcdurak added the run-slow-ci label Jul 21, 2025

schustmi approved these changes Jul 21, 2025

View reviewed changes

new changes

71e05e2

schustmi requested changes Jul 23, 2025

View reviewed changes

src/zenml/logging/step_logging.py Outdated Show resolved Hide resolved

most recent changes

90b7236

bcdurak added 5 commits July 24, 2025 14:28

formatting

84bb2d6

on final change

a781823

checkpoint

815272e

new checkpoint

6ddbcb4

save time

6a19152

bcdurak requested a review from schustmi July 25, 2025 14:55

schustmi requested changes Jul 28, 2025

View reviewed changes

new changes

611ad84

schustmi reviewed Jul 28, 2025

View reviewed changes

src/zenml/logging/step_logging.py Outdated Show resolved Hide resolved

bcdurak added 3 commits July 28, 2025 11:36

change

a7622f8

keep failing and increase process interval to 5 secs

1891d64

new changes after the comments

a1987da

bcdurak requested a review from schustmi July 28, 2025 12:50

bcdurak added 2 commits July 28, 2025 15:18

new changes

c12f39b

removed unused method

0f3defc

zenml-io deleted a comment from github-actions bot Jul 28, 2025

Merge branch 'develop' into bugfix/gcsfs-log-interactions

8f7d945

schustmi requested changes Jul 28, 2025

View reviewed changes

src/zenml/logging/step_logging.py Show resolved Hide resolved

new constants

70357b0

bcdurak requested a review from schustmi July 28, 2025 15:26

bcdurak added 3 commits July 28, 2025 17:54

docstrings

c1322b7

docstrings again

2150dc8

fix qsize

dc6cf2a

schustmi approved these changes Jul 28, 2025

View reviewed changes

bcdurak and others added 2 commits July 29, 2025 10:14

linting and gcp\

23eb8cd

Merge branch 'develop' into bugfix/gcsfs-log-interactions

6c246be

bcdurak merged commit f230daa into develop Jul 29, 2025
22 of 52 checks passed

bcdurak deleted the bugfix/gcsfs-log-interactions branch July 29, 2025 08:47

This was linked to issues Jul 30, 2025

[BUG]: Duplicate log entries in artifact stores with immutable filesystems #3849

Closed

[FEATURE]: Create a I/O background thread to handle the logging #3857

Closed

Solving the race conditions for logging #3855

Solving the race conditions for logging #3855

Uh oh!

Conversation

bcdurak commented Jul 18, 2025

Describe changes

Pre-requisites

Types of changes

Uh oh!

coderabbitai bot commented Jul 18, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Review skipped

Chat

Support

CodeRabbit Commands (Invoked using PR comments)

Other keywords and placeholders

Documentation and Community

Uh oh!

Uh oh!

schustmi left a comment

Choose a reason for hiding this comment

Uh oh!

bcdurak commented Jul 21, 2025

Uh oh!

schustmi left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

bcdurak commented Jul 23, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

bcdurak commented Jul 23, 2025

Uh oh!

bcdurak commented Jul 25, 2025

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

coderabbitai bot commented Jul 18, 2025 •

edited

Loading

schustmi left a comment •

edited

Loading

bcdurak commented Jul 23, 2025 •

edited

Loading