Support multiple event files that contain events not in chronological order

[Corwinpro]

Use case

Sometimes, a model can be iteratively trained on multiple workers (e.g., using mutliprocessing). In that case, there is an tfevent_* file for each of the workers. So when the model is trained on worker_1, the events are persisted in the tfevent_1 file. Then, the model training can be dedicated to a different worker (worker_2) and the events are persisted in the tfevent_2 file. For next iterations, the model can be trained on worker_1 again, which means that the tfevent_1 is used.

The issue is that the we end up having tfevent files that contain events in non-chronological order:

tfevent_1 file:

• event 1
• event 3

tfevent_2 file:

• event 2

And rustboard fails to read them properly.

This is not a bug since this is a documented behaviour:

tensorboard/tensorboard/data/server/logdir.rs

Line 36 in f45fdd6

/// Event files within each run should be emitted in chronological order. Canonically, a file

Feature request

Allow rustboard to parse data in partially-chronological order.

[bmd3k]

Hi @Corwinpro, thanks for the feature request.

In fact, we think it's possible that rustboard can read events as you describe but we also think there are some scenarios where this would fail. If you could provide a minimal reproduction that would possibly help us better understand what you want and why it's not workign for you.

Additionally, it would be nice to know what behavior you observe when you disable rustboard (--load_fast=false) and additionally when you enable multifile mode without rustboard (--reload_multifile=true).

[Corwinpro]

Thank you for looking into this @bmd3k ! I can confirm that neither --reload_multifile=true nor --load_fast=false (nor any combination of those) solve the problem. I will provide an example data soon.

[Corwinpro]

I attach 3 + 1 files that illustrate the problematic case and an expected behaviour.

The problematic case.

We have 3 files, created in the presented order, that contain dummy events data for multiple ranges of steps:

• File 1: contains events with steps [0, 9], [20, 29], [50, 59]
• File 2 (created after File 1): contains events with steps [10, 19], [40, 49]
• File 3 (created after File 2): contains events with steps [30, 39]

All 3 files are in the same log directory.

Running tensorboard with this, I would expect it to pick up the full range [0, 59] because all steps in that range are present in the tfevent files.

The actual behaviour is: tensorboard takes [0, 9] from File 1, [10, 19] from File 2, [30, 39] from File 3. Other ranges ([20, 29], [40, 49], [50, 59]) are ignored because those exist in "old" files in comparison to the currently read ones.

Please find File 1-3 here:

dir1.zip

Expected behaviour

I manually merge the content of the files, and put all ranges in a single file. In that case, tensorboard naturally can read it just fine.

Please find the combined file here:

events.out.tfevents.1665653533.zip

[nfelt]

Thanks for the additional details. This is not actually a problem with the logic in logdir.rs (that's just about the ordering of filenames within a directory).

The reason that this isn't working as you want it to is that Rustboard includes automatic support for handling preemptions in training jobs:

tensorboard/tensorboard/data/server/reservoir.rs

Lines 33 to 47 in f45fdd6

	/// # Preemption
	///
	/// All records stored in this reservoir have a *step* and a *payload*. The step, a non-negative
	/// integer, is expected to be monotonically (strictly) increasing over time. Whenever a new record
	/// arrives with step `s`, it preempts any records with steps not smaller than `s`.
	///
	/// This is motivated by preemptions of nondeterministic training jobs. If a job is checkpointed at
	/// step 80 and preempted at step 100, any metrics written between steps 81 and 100 will be
	/// recomputed when the job restarts. Since the outputs may be nondeterministic, the old values
	/// must be discarded to avoid a misleading discontinuity between steps 100 and 101.
	///
	/// For the purpose of this reservoir, preemption is considered a normal mode of operation, not an
	/// error. However, jobs incorrectly configured to emit non-increasing steps without being
	/// preempted may find that this reservoir does not behave as they expect. For instance, a job that
	/// emits many records all at step 0 will find that only one record is retained in the reservoir.

When we see a file A that contains steps 0-9 and 20-29, followed by a file B that contains steps 10-19, the file reading code assumes that what you actually had was a job failure - where its first attempt ran from step 0 to 29, then failed, restarted at step 10, and produced file B. So the logic deliberately discards steps 20-29 from file A as it assumes they represent obsolete data.

One thing to note is that the logic "sees" the events as it reads them from files, so this effect wouldn't happen if the logic reads steps 0-9 from file A while they're still the only data in the file, then reads 10-19 from file B, and then only sees steps 20-29 from file A when it polls the files for new data. In other words, if you run TensorBoard concurrently while the workers are processing and they are not especially fast, you should see the data load as you expect.

We've gotten occasional requests for supporting out-of-order steps (Googlers, see b/72185341), but don't have any particular plan to support it right now. The reason it's difficult is that in the general case it's pretty much impossible to deliberate out-of-order steps (like this case) from out-of-order steps that result from preemptions.

The main workarounds available are:

• write each segment of data (0-9, 10-19, 20-29) into its own file, and try to ensure that the workers process those segments in order (resulting in filenames that are in the expected sorted order)
• postprocess the files to re-arrange the data into sorted order

[Corwinpro]

Thank you very much @nfelt , I think this makes sense.

Writing segments to its own file is a good solution. Given that the motivation for the current behaviour has been explained, I am happy to close the issue.

[nfelt]

Glad that helped. It's probably good if we have a tracking issue for this (even if we don't have an immediate plan to address it), so I'll leave this open.