Monitors always write to stdout

[untom]

Currently, all monitors write to stdout. If brainstorm is used from an IPython notebook, and some monitor as an update interval, this will inevitably lead to a completely frozen browser session, as IPython notebooks usually cannot deal with the massive amount of output produced by many monitors.

It would be nice if the user could set where each monitors writes its output. sys.stdout is a sensible default, but for many applications it makes more sense to log to a file instead. Ideally this setting could be changed on a per-monitor basis, where the destination (or whatever one wants to call it) parameter could either be a file-like object or a string denoting a filename.

(Optionally, we could still print to stdout and a file if verbose==True, and just to the file if verbose==False)

[Qwlouse]

Should we maybe move to a full-blown logging integration? That way we'd get all the configuration options for writing to (rotating) files, filtering the messages, sending via http/smtp and so on for free.

[untom]

In my opinion full blown logging (á la logging module in the stdlib) adds more complexity that we need for now

[untom]

I think a basic implementation could just add a destination/sink/file (which one do you prefer?) parameter to the constructor, which would store the corresponding file-object, and then net._add_log could just print to that file instead of using the print function (or it could do both, if verbose==True). Does that sound sensible to you?

[flukeskywalker]

We agree, it does not look like we need full blown logging.

@untom: There are three alternatives we can suggest monitoring large amount of logs, say from update-wise logs:

1. Post training analysis: set the update-wise hook verbosity to False so it doesn't print but still appends to logs. After training is done, you can directly access/save the trainer.logs and plot them, compute statistics etc.
2. Analysis during training: Use a simple Hook to dump the trainer logs dictionary periodically to file(s).
3. Use Sacred ;)

Is there a reason why having a write to file option directly in the monitors/trainer would be preferable over these?

[untom]

1 and 3 aren't options because they don't allow you to monitor things while training happens (e.g. it's frustrating to wait for 2 days for a run to finish only to see that there were problems 2 iterations after the start). Option 2 would work, but is a way more roundabout way, IMO.

[flukeskywalker]

The InfoUpdater hook actually submits the logs to the database at every call. We have used it this way and it was pretty handy.
Currently it only supports being called at every epoch, but we should extend it so that it can be called at every update.

Regarding adding a direct option to dump logs to a file, I'm in favor of this if it seems useful. I think it should be an option to trainer though, not the hooks, for simplicity. However, the reason I thought it should be a hook is that hooks already provide control over the timescale and interval for their execution. If we put this as an option in the Trainer, we'll need to provide these options separately (which would be sort of a duplication).

[untom]

The problem with having this option is that I might want to have some output displayed on screen (e.g. per-epoch accuracy or even per-epoch parameter statistics) and other output on file (e.g. per-update parameter statistics).

[flukeskywalker]

In that case you would have verbosity for Trainer to be True (default), specify the filename to dump logs to, and set verbosity for per update hooks to False.
You'll note that hook verbosity is pretty smart: it inherits from Trainer by default, but can be changed if desired :)

As I noted earlier though, we'll either need to provide additional args to Trainer to specify how often it should dump to file, or fix this schedule.

[untom]

That solution seems a bit hackish to me, I don't think it's very intuitive for new users. It also makes it impossible to log different hooks into different files.

[flukeskywalker]

To be clear, the verbosity behavior is how the hooks work already. It does seem like a bit of flexibility that may not be needed. We have this so that you don't have to specify the verbosity for each hook separately (just saves some typing).

Edit: I agree it's non-intuitive for new users, specially without any docs ;)

Firstly, is there a use case where it'd be required to log different hooks into different files?

Secondly, the hooks currently don't print the logs or maintain them. They simply return the data to trainer whose job is to aggregate all the logs. This makes some things less complicated e.g.

1. The sacred InfoUpdater which simply has to submit the logs.
2. An upcoming hook that will decrease the learning rate if some logged quantity has not decreased in a while.

[flukeskywalker]

@untom, any ideas for tackling this issue?

[ntfrgl]

This sounds like a perfect introductory exercise for me.

Several years ago, I used logging for a much smaller framework than this, including fine-grained verbosity and destination configuration as well as fusion of logging streams from different processes. I don't think you would gain either in short-term or in long-term by not using logging, and I don't see a reason why per-hook logging flexibility shouldn't be incorporated now. During initialization, you would create several application-specific default logger instances, and then a monitor would just grab one of them from the environment and fine-tune it, using his optional invocation parameter holding a standard logging configuration dictionary.

If you guys agree on what options should be available, I could draft a PR soon.

[flukeskywalker]

@ntfrgl, nice to see you paying attention to the issues already!

Here's my current take on this issue. I don't feel that we gain much from incorporating full blown logging currently (in agreement with @untom). Gains from not using logging in the short-term:

1. Having less functionality and focusing on tightening it up early in the project.
2. Spending available time on more important things like writing tests, data iterators for databases and file-lists (which Caffe uses), having larger and more diverse example models such as ImageNet/MIT-Places, more complex architectures such as Encoder-Decoder, more layers etc.

In my experience, having used Pylearn2, Caffe, Pybrain, Pylstm etc. etc., I have not had a proper use case for a logging mechanism with very fine controls. Caffe does use glog, but only provides a couple of logging levels for debug mode etc. In addition, one can easily combine Sacred with Brainstorm using the InfoUpdater hook to log everything to a MongoDB while running.

We can incorporate proper logging in the future if this becomes a common feature request and the use cases become more evident. Additionally, we might make slight changes to how hooks work in the next month, so we should hold off on incorporating logging at least until then.

[Qwlouse]

I've added the SaveLogs hook that saves all the logs to an HDF5 file. I think this should cover most use cases where some monitors shouldn't be printed but need to be kept somewhere. If you guys agree I would close this issue. @untom: thoughts?

[halcy]

I'd strongly suggest that whatever the end result may be, it should either directly write to pythons logging, so that when brainstorm is used from other code, together with other libraries (which is maybe not the norm, but is definitely our use case), you end up with all the log output in one place, rather than having several different logging facilities.

Edit: I've added a small pull request to that end that simply allows for passing any function to trainer or hooks, which will then call that function instead of print (with print() being the default function used, so if print is fine, no code using trainer or hooks needs to be changed)