Question about the log file

zsz-pro commented 1 year ago

Thanks for your great work! The log file gets me a little confused. Take epoch2 as an example, it appears 5 times, could you please give some explanations? Epoch 1 - Evaluation time (seconds): 4.40 - Vis metrics: abs_rel: 0.16088220118284555 sq_rel: 1.6475946958800654 rmse: 6.0004214998035215 rmse_log: 0.2652074425737867 a1: 0.8132480978965759 a2: 0.9111361503601074 a3: 0.9498652219772339 2023-07-08 16:39:02,464 kitti_raw INFO: Epoch[1] Complete. Time taken: 00:46:03.668 [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [2023-07-08 16:39:19,277][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) Evaluation (val): [1/1] 100%|███████████████████████████████████████████████████████████████████████████████████████ [00:00<?]Visualizing [2023-07-08 16:39:23,725][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:00:04.238
[2023-07-08 16:39:23,725][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:00:04.447 2023-07-08 16:39:23,809 kitti_raw INFO: Epoch 2 - Evaluation time (seconds): 4.45 - Vis metrics: abs_rel: 0.23017341934595395 sq_rel: 3.088896086703511 rmse: 7.271316281467014 rmse_log: 0.3078563333555099 a1: 0.7813498377799988 a2: 0.8981010913848877 a3: 0.9393996000289917 [2023-07-08 16:47:56,868][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) Evaluation (val): [1/1] 100%|███████████████████████████████████████████████████████████████████████████████████████ [00:00<?]Visualizing [2023-07-08 16:48:01,295][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:00:04.211
[2023-07-08 16:48:01,296][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:00:04.427 2023-07-08 16:48:01,401 kitti_raw INFO: Epoch 2 - Evaluation time (seconds): 4.43 - Vis metrics: abs_rel: 0.1650394400605743 sq_rel: 1.998698890271272 rmse: 5.943043702966046 rmse_log: 0.2682881054646016 a1: 0.8516638278961182 a2: 0.9178416728973389 a3: 0.9528733491897583 [2023-07-08 16:56:36,516][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) Evaluation (val): [1/1] 100%|███████████████████████████████████████████████████████████████████████████████████████ [00:00<?]Visualizing [2023-07-08 16:56:40,894][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:00:04.135
[2023-07-08 16:56:40,895][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:00:04.378 2023-07-08 16:56:40,991 kitti_raw INFO: Epoch 2 - Evaluation time (seconds): 4.38 - Vis metrics: abs_rel: 0.14595142936506972 sq_rel: 1.4979753871574057 rmse: 5.749837607629393 rmse_log: 0.26670149436806356 a1: 0.8354953527450562 a2: 0.9211630821228027 a3: 0.9507426023483276 conda activate base [2023-07-08 17:05:13,192][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [2023-07-08 17:08:11,160][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:02:57.756
[2023-07-08 17:08:11,161][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:02:57.969 2023-07-08 17:08:11,282 kitti_raw INFO: Epoch 2 - Evaluation time (seconds): 177.97 - Test metrics: abs_rel: 0.11900233822874062 sq_rel: 0.8671512578064269 rmse: 4.559270895221629 rmse_log: 0.199316740456192 a1: 0.8598688319325447 a2: 0.9558506403118372 a3: 0.9797724287491292 [2023-07-08 17:08:11,282][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) Evaluation (val): [1/1] 100%|███████████████████████████████████████████████████████████████████████████████████████ [00:00<?]Visualizing [2023-07-08 17:08:15,634][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:00:04.166
[2023-07-08 17:08:15,635][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:00:04.353 2023-07-08 17:08:15,740 kitti_raw INFO: Epoch 2 - Evaluation time (seconds): 4.35 - Vis metrics: abs_rel: 0.13582281319264153 sq_rel: 1.4082434631998875 rmse: 6.013943428623624 rmse_log: 0.28424850291586035 a1: 0.8557999134063721 a2: 0.923481822013855 a3: 0.9515572786331177 [2023-07-08 17:16:50,828][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) Evaluation (val): [1/1] 100%|███████████████████████████████████████████████████████████████████████████████████████ [00:00<?]Visualizing [2023-07-08 17:16:55,211][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:00:04.195
[2023-07-08 17:16:55,212][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:00:04.384 2023-07-08 17:16:55,296 kitti_raw INFO: Epoch 2 - Evaluation time (seconds): 4.38 - Vis metrics: abs_rel: 0.17579734838730143 sq_rel: 2.5830991379591985 rmse: 6.899043454084597 rmse_log: 0.30531200850440265 a1: 0.8277871608734131 a2: 0.9161496162414551 a3: 0.941655695438385 2023-07-08 17:25:02,273 kitti_raw INFO: Epoch[2] Complete. Time taken: 00:45:59.807 [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [2023-07-08 17:25:31,259][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) [W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) Evaluation (val): [1/1] 100%|████████████████████████████████████████████████████████████████████████ [00:00<?]Visualizing [2023-07-08 17:25:35,633][ignite.engine.engine.Engine][INFO] - Epoch[1] Complete. Time taken: 00:00:04.175
[2023-07-08 17:25:35,634][ignite.engine.engine.Engine][INFO] - Engine run complete. Time taken: 00:00:04.374 2023-07-08 17:25:35,720 kitti_raw INFO: Epoch 3 - Evaluation time (seconds): 4.37 - Vis metrics: abs_rel: 0.15186456882564142 sq_rel: 2.0138081328306496 rmse: 6.890541053109251 rmse_log: 0.2912098378889751 a1: 0.846023678779602 a2: 0.9128282070159912 a3: 0.944538414478302

Brummi commented 1 year ago

Hi! I dont observe the same behaviour on any of our machines. I think this is an issue with your system setup. Best, Felix

Nicholas-Autio-Mitchell commented 1 year ago

I see the same kind of logs as described by @zsz-pro.

Is the reason simply because there are multiple validation/visualisation steps per epoch? These lines of the default configuration file suggest that is true.

Running the KITTI-360 experiment: The things I changed:

change is_preprocess in this dataset config to be false (avoiding the resize)
adding (hacky) fix at script entrypoint due to this issue, where torch's linalg module evaluates lazily, which breaks multi-GPU training with CUDA version < 11.7. I am surprised

I am kind of surprised this is not an issue for the repo's given conda environment as it uses pytorch-cuda=11.6.

Below is a chunk of the training logs that show Epochs 13, 14 and 15. Like all other epochs, some logs are printed multiple times.

Expand to see logs

## Trained on single A100 GPU ```bash [2023-07-12 14:11:15,398][ignite.engine.engine.Engine][INFO] - Engine run starting with max_epochs=1. Evaluation (val): [1/1] 100%|████████████████████████████████████████████████████████████████████████████ [00:00

I think we see Epoch [1] for every round of evaluation.

After epochs 13 and 14 finish (in my logs above), we do actually see a log line stating that is finished:

2023-07-12 19:55:05,461 kitti_360 INFO: Epoch[14] Complete. Time taken: 05:37:18.031

Brummi commented 1 year ago

Hi, sorry, I thought you were talking about the W pthreadpool-cpp.cc:90] Warning: Leaking Caffe2 thread-pool after fork. (function pthreadpool) line.

Yes, evaluation is not based on epochs, but iterations. This was very useful when dealing with datasets of different sizes. For example RealEstate10K has a huge number of datapoints. Here, evaluating only every epoch would not give you a good overview of the training.
is_preprocessed speeds up training because you don't have to load the full-sized images, but the already resized ones. (Theses files can be obtained from the script in the datasets/kitti-360 directory.
I have not really used multi-GPU training during development. Therefore, this issue might have not appeared

zsz-pro commented 1 year ago

I got it！Thanks for your reply！

Brummi / BehindTheScenes

Question about the log file #23