Hydra: [Bug] logging error on shutdown when using PL and Wandb logger

[omry]

Repro here.

Once fixed backport to 1.0.

[tadejsv]

I've narrowed down the error: it is caused by the reinit=True option in wandb.init() (which PL sets by default).

I've also updated the repository to show this and removing the PL dependency.

[jieru-hu]

UPDATE:

Pls ignore this comment. I missed some context from the wandb issue. Sorry!

---

Thx @tadejsv for the repro, that helps a lot!

Following wandb's doc here https://docs.wandb.com/library/init#how-do-i-launch-multiple-runs-from-one-script
I added wandb_log.finish() to your script like the following

$ git diff
diff --git a/main.py b/main.py
index 4a6a113..aa7a138 100644
--- a/main.py
+++ b/main.py
@@ -62,7 +62,8 @@ def run_train(cfg: DictConfig) -> None:
         if batch_idx % 100 == 0:
             wandb_log.log({"loss": loss})
             log.info('loss %s', loss)
-            
+
+    wandb_log.finish()
     log.info('Finished training')

After applying change the errors went away, and I've attached the running log below. Could you try the approach recommended in their doc as well?

$ HYDRA_FULL_ERROR=1 python main.py -m learning_rate=1e-3
[2020-11-11 13:15:23,876][HYDRA] Launching 1 jobs locally
[2020-11-11 13:15:23,876][HYDRA]        #0 : learning_rate=0.001
[2020-11-11 13:15:24,263][wandb][WARNING] - could not find program at main.py
[2020-11-11 13:15:24,269][wandb][INFO] - setting login settings: {}
wandb: Offline run mode, not syncing to the cloud.
wandb: W&B is disabled in this directory.  Run `wandb on` to enable cloud syncing.
[2020-11-11 13:15:24,834][__main__][INFO] - Starting training
[2020-11-11 13:15:26,764][__main__][INFO] - loss tensor(2.7919, grad_fn=<NllLossBackward>)
[2020-11-11 13:15:26,843][__main__][INFO] - loss tensor(1.0686, grad_fn=<NllLossBackward>)
[2020-11-11 13:15:26,917][__main__][INFO] - loss tensor(2.4863, grad_fn=<NllLossBackward>)
[2020-11-11 13:15:26,989][__main__][INFO] - loss tensor(7.4453, grad_fn=<NllLossBackward>)

wandb: Waiting for W&B process to finish, PID 2990
wandb: Program ended successfully.
wandb: Find user logs for this run at: wandb/offline-run-20201111_131524-9osp8zj4/logs/debug.log
wandb: Find internal logs for this run at: wandb/offline-run-20201111_131524-9osp8zj4/logs/debug-internal.log
wandb: Run summary:
wandb:                    loss 7.44532
wandb:                   _step 3
wandb:                _runtime 2
wandb:              _timestamp 1605129326
wandb: Run history:
wandb:         loss ▃▁▃█
wandb:        _step ▁▃▆█
wandb:     _runtime ▁▁▁▁
wandb:   _timestamp ▁▁▁▁
wandb: 
wandb: You can sync this run to the cloud by running:
wandb: wandb sync wandb/offline-run-20201111_131524-9osp8zj4
[2020-11-11 13:16:30,108][__main__][INFO] - Finished training

[tomsercu]

Unfortunately this doesn't resolve the issue if you do more than 2 runs with multirun. See this gist. I'll comment more in https://github.com/wandb/client/issues/1314

[omry]

@jieru-hu, what I was thinking here is to put a try-catch around flushes of the loggers (the point in the code that is throwing the exception).
The exception can just be ignored. since the file is already closed (or otherwise invalid) there is nothing to flush and we should continue to the next handler.

[jieru-hu]

Thx @tomsercu! I missed some of the comments in the original wandb issue, sorry for the confusion.

@omry
I don't think the exceptions are from _flush_loggers. To verify, i added try-except around the code and no exception was thrown from there.

It seems to me something that needs to be fixed on wandb side, let's chat in person tomorrow on this.

[omry]

This is the original report, the stack trace there contains an exception from _flush_loggers(). That exception is probably just a red herring though and I am not surprised that there are other issues if the log handler file was closed.