[caffe2] Run resnet50_trainer.py error between 2 machines using GLOO/Redis

[bkovalev]

• Caffe2

• OS: Ubuntu 16.04
  -- Python version: 2.7

• CUDA/cuDNN version: 9.1 , 7.0.5

• GPU models and configuration: P100

• GCC version (if compiling from source):5.4.0

• Mellanox OFEDversion: 4.2.1

• Build command you used (if compiling from source):

  Eigen with CUDA9: fatal error：math_functions.hpp：No such file or directory.

Was fixed in eigen at https://bitbucket.org/eigen/eigen/commits/034b6c3e101792a3cc3ccabd9bfaddcabe85bb58?at=default

$ mkdir build
$ cd build
$ cmake .. -DCUDA_ARCH_NAME=Manual -DCUDA_ARCH_BIN="60 61" -DCUDA_ARCH_PTX="61" -DUSE_NNPACK=OFF -DUSE_ROCKSDB=OFF -DUSE_GLOO=ON -DUSE_REDIS=ON -DUSE_IBVERBS=ON -DUSE_MPI=OFF
$ make -j"$(nproc)" install
$ ldconfig
$ make clean

I try to run resnet50_trainer.py on one node by:
python /root/caffe2/caffe2/python/examples/resnet50_trainer.py --train_data /data/ilsvrc12_train_lmdb/ --test_data /data/ilsvrc12_val_lmdb --batch_size 64 --epoch_size 10000 --num_epochs 2 --image_size 256 --num_gpus 4

and have result: ~ 430 imgs/sec

When I try to run resnet50_trainer.py between 2 machines using GLOO/Redis, but I get the following error messages.
How to fix the error and run correctly using mpirun?

My commands:
On each node was ran the sample command:
python /root/caffe2/caffe2/python/examples/resnet50_trainer.py --train_data /data/ilsvrc12_train_lmdb/ --test_data /data/ilsvrc12_val_lmdb --batch_size 32 --run_id 1 --epoch_size 10000 --num_epochs 2 --image_size 256 --num_gpus 1 --redis_host 10.143.119.44 --redis_port 5555 --num_shards 2 --shard_id 0 --dtype float16 --float16_compute --distributed_transport ibverbs --distributed_interfaces mlx5_3

python /root/caffe2/caffe2/python/examples/resnet50_trainer.py --train_data /data/ilsvrc12_train_lmdb/ --test_data /data/ilsvrc12_val_lmdb --batch_size 32 --run_id 1 --epoch_size 10000 --num_epochs 2 --image_size 256 --num_gpus 1 --redis_host 10.143.119.44 --redis_port 5555 --num_shards 2 --shard_id 1 --dtype float16 --float16_compute --distributed_transport ibverbs --distributed_interfaces mlx5_3

Errors:
INFO:resnet50_trainer:Finished iteration 155/156 of epoch 0 (207.29 images/sec)
INFO:resnet50_trainer:Training loss: 0.000181300914846, accuracy: 1.0
INFO:resnet50_trainer:Finished iteration 156/156 of epoch 0 (204.85 images/sec)
INFO:resnet50_trainer:Training loss: 0.00019393475668, accuracy: 1.0
E0404 16:13:32.042721 39912 prefetch_op.h:110] Prefetching error std::bad_alloc
E0404 16:13:32.042976 39911 prefetch_op.h:83] Prefetching failed.
E0404 16:13:32.043117 39911 net_dag.cc:231] Operator chain failed starting at: input: "test_reader" output: "gpu_0/data" output: "gpu_0/label" name: "" type: "ImageInput" arg { name: "std" f: 128 } arg { name: "scale" i: 256 } arg { name: "use_gpu_transform" i: 1 } arg { name: "cudnn_exhaustive_search" i: 1 } arg { name: "crop" i: 256 } arg { name: "is_test" i: 1 } arg { name: "use_cudnn" i: 1 } arg { name: "use_caffe_datum" i: 1 } arg { name: "mirror" i: 1 } arg { name: "output_type" s: "float16" } arg { name: "batch_size" i: 32 } arg { name: "mean" f: 128 } device_option { device_type: 1 cuda_gpu_id: 0 }
E0404 16:13:32.043376 39646 net.h:54] Failed to execute async run
Original python traceback for operator 1886221678 in network resnet50_test in exception above (most recent call last):
Traceback (most recent call last):
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 615, in
main()
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 611, in main
Train(args)
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 529, in Train
explog
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 201, in RunEpoch
workspace.RunNet(test_model.net.Proto().name)
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/workspace.py", line 215, in RunNet
StringifyNetName(name), num_iter, allow_fail,
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/workspace.py", line 177, in CallWithExceptionIntercept
return func(*args, **kwargs)
RuntimeError: [enforce fail at pybind_state.cc:1001] success. Error running net resnet50_test

O second node:
INFO:resnet50_trainer:Training loss: 6.98969364166, accuracy: 0.0
INFO:resnet50_trainer:Finished iteration 156/156 of epoch 0 (205.14 images/sec)
INFO:resnet50_trainer:Training loss: 6.99336242676, accuracy: 0.0
INFO:resnet50_trainer:Starting epoch 1/2
terminate called after throwing an instance of 'gloo::EnforceNotMet'
what(): [enforce fail at /root/caffe2/third_party/gloo/gloo/transport/ibverbs/pair.cc:417] wc->status == IBV_WC_SUCCESS. 12 vs 0. Send for slot 2: transport retry counter exceeded
*** Aborted at 1522847623 (unix time) try "date -d @1522847623" if you are using GNU date ***
PC: @ 0x7f84fc58e428 gsignal
*** SIGABRT (@0x9a14) received by PID 39444 (TID 0x7f83ebf8d700) from PID 39444; stack trace: ***
@ 0x7f84fc58e4b0 (unknown)
@ 0x7f84fc58e428 gsignal
@ 0x7f84fc59002a abort
@ 0x7f848079584d __gnu_cxx::__verbose_terminate_handler()
@ 0x7f84807936b6 (unknown)
@ 0x7f8480793701 std::terminate()
@ 0x7f84807bed38 (unknown)
@ 0x7f84fc92a6ba start_thread
@ 0x7f84fc66041d clone
@ 0x0 (unknown)
Aborted (core dumped)

[pjh5]

@pietern this looks like a question on how to use Redis correctly

[pietern]

It looks like you're using the distributed functionality properly. The first machine throws an error "Prefetching error std::bad_alloc" and terminates, which makes the second machine time out on trying to communicate with the first machine. I think the real problem here lies in prefetch_op.h, not ibverbs.

Can this error be reproduced consistently? If so, can you look at memory usage of both processes over time? The std::bad_alloc makes me think this can be out of memory related.

[bkovalev]

@pietern Yes this error can be reproduced consistently.
RAM memory usage on both processes around 4,5GB.
GPU memory usage on both processes arround 3,7GB.
Thanks

[bkovalev]

When I execute multi GPU per host by

python /root/caffe2/caffe2/python/examples/resnet50_trainer.py --train_data /data/ilsvrc12_train_lmdb/ --test_data /data/ilsvrc12_val_lmdb --batch_size 32 --run_id 1 --epoch_size 10000 --num_epochs 2 --image_size 256 --num_gpus 4 --redis_host 10.143.119.44 --redis_port 5555 --num_shards 2 --shard_id 0 --dtype float16 --float16_compute --distributed_transport ibverbs --distributed_interfaces mlx5_3

python /root/caffe2/caffe2/python/examples/resnet50_trainer.py --train_data /data/ilsvrc12_train_lmdb/ --test_data /data/ilsvrc12_val_lmdb --batch_size 32 --run_id 1 --epoch_size 10000 --num_epochs 2 --image_size 256 --num_gpus 4 --redis_host 10.143.119.44 --redis_port 5555 --num_shards 2 --shard_id 1 --dtype float16 --float16_compute --distributed_transport ibverbs --distributed_interfaces mlx5_3

I have another issue.

On first node i see

INFO:resnet50_trainer:Running on GPUs: [0, 1, 2, 3]
INFO:resnet50_trainer:Using epoch size: 9984
INFO:data_parallel_model:Parallelizing model for devices: [0, 1, 2, 3]
INFO:data_parallel_model:Create input and model training operators
INFO:data_parallel_model:Model for GPU : 0
INFO:data_parallel_model:Model for GPU : 1
INFO:data_parallel_model:Model for GPU : 2
INFO:data_parallel_model:Model for GPU : 3
INFO:data_parallel_model:Adding gradient operators
INFO:data_parallel_model:Add gradient all-reduces for SyncSGD
WARNING:data_parallel_model:Distributed broadcast of computed params is not implemented yet
INFO:data_parallel_model:Post-iteration operators for updating params
INFO:data_parallel_model:Calling optimizer builder function
INFO:data_parallel_model:Add initial parameter sync
E0405 22:24:37.457337 17253 operator.cc:463] Shape inference error: [enforce fail at conv_pool_op_base.h:601] in_size + *pad_head + *pad_tail >= dkernel. 2 vs 3
E0405 22:24:37.457785 17253 operator.cc:464] Operator: input: "gpu_0/conv1_spatbn_relu" output: "gpu_0/pool1" name: "" type: "MaxPool" arg { name: "order" s: "NCHW" } arg { name: "kernel" i: 3 } arg { name: "stride" i: 2 } arg { name: "ws_nbytes_limit" i: 67108864 } arg { name: "cudnn_exhaustive_search" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "CUDNN"
E0405 22:24:37.457815 17253 operator.cc:465] Returning empty results.
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0757119655609 secs
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0735418796539 secs
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0704200267792 secs
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0703098773956 secs
INFO:resnet50_trainer:----- Create test net ----
INFO:data_parallel_model:Parallelizing model for devices: [0, 1, 2, 3]
INFO:data_parallel_model:Create input and model training operators
INFO:data_parallel_model:Model for GPU : 0
INFO:data_parallel_model:Model for GPU : 1
INFO:data_parallel_model:Model for GPU : 2
INFO:data_parallel_model:Model for GPU : 3
INFO:data_parallel_model:Parameter update function not defined --> only forward
INFO:resnet50_trainer:Starting epoch 0/2

On second node:
Ignoring @/caffe2/caffe2/contrib/nccl:nccl_ops as it is not a valid file.
Ignoring @/caffe2/caffe2/contrib/gloo:gloo_ops as it is not a valid file.
Ignoring @/caffe2/caffe2/contrib/gloo:gloo_ops_gpu as it is not a valid file.
Ignoring @/caffe2/caffe2/distributed:file_store_handler_ops as it is not a valid file.
Ignoring @/caffe2/caffe2/distributed:redis_store_handler_ops as it is not a valid file.
E0405 22:24:39.795949 24032 init_intrinsics_check.cc:43] CPU feature avx is present on your machine, but the Caffe2 binary is not compiled with it. It means you may not get the full speed of your CPU.
E0405 22:24:39.796234 24032 init_intrinsics_check.cc:43] CPU feature avx2 is present on your machine, but the Caffe2 binary is not compiled with it. It means you may not get the full speed of your CPU.
E0405 22:24:39.796247 24032 init_intrinsics_check.cc:43] CPU feature fma is present on your machine, but the Caffe2 binary is not compiled with it. It means you may not get the full speed of your CPU.
INFO:resnet50_trainer:Running on GPUs: [0, 1, 2, 3]
INFO:resnet50_trainer:Using epoch size: 9984
INFO:data_parallel_model:Parallelizing model for devices: [0, 1, 2, 3]
INFO:data_parallel_model:Create input and model training operators
INFO:data_parallel_model:Model for GPU : 0
INFO:data_parallel_model:Model for GPU : 1
INFO:data_parallel_model:Model for GPU : 2
INFO:data_parallel_model:Model for GPU : 3
INFO:data_parallel_model:Adding gradient operators
INFO:data_parallel_model:Add gradient all-reduces for SyncSGD
WARNING:data_parallel_model:Distributed broadcast of computed params is not implemented yet
INFO:data_parallel_model:Post-iteration operators for updating params
INFO:data_parallel_model:Calling optimizer builder function
INFO:data_parallel_model:Add initial parameter sync
E0405 22:24:40.959513 24032 operator.cc:463] Shape inference error: [enforce fail at conv_pool_op_base.h:601] in_size + *pad_head + *pad_tail >= dkernel. 2 vs 3
E0405 22:24:40.960314 24032 operator.cc:464] Operator: input: "gpu_0/conv1_spatbn_relu" output: "gpu_0/pool1" name: "" type: "MaxPool" arg { name: "order" s: "NCHW" } arg { name: "kernel" i: 3 } arg { name: "stride" i: 2 } arg { name: "ws_nbytes_limit" i: 67108864 } arg { name: "cudnn_exhaustive_search" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "CUDNN"
E0405 22:24:40.960363 24032 operator.cc:465] Returning empty results.
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0762090682983 secs
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.111880064011 secs
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0926520824432 secs
WARNING:memonger:NOTE: Executing memonger to optimize gradient memory
INFO:memonger:Memonger memory optimization took 0.0926530361176 secs
INFO:resnet50_trainer:----- Create test net ----
INFO:data_parallel_model:Parallelizing model for devices: [0, 1, 2, 3]
INFO:data_parallel_model:Create input and model training operators
INFO:data_parallel_model:Model for GPU : 0
INFO:data_parallel_model:Model for GPU : 1
INFO:data_parallel_model:Model for GPU : 2
INFO:data_parallel_model:Model for GPU : 3
INFO:data_parallel_model:Parameter update function not defined --> only forward
INFO:resnet50_trainer:Starting epoch 0/2
E0405 22:24:57.784853 24154 net_dag.cc:188] Exception from operator chain starting at 'last_out_L1000_b_grad' (type 'Allreduce'): caffe2::EnforceNotMet: [enforce fail at context_gpu.h:155] . Encountered CUDA error: invalid resource handle Error from operator:
input: "allreduce_0_cw" input: "gpu_0/last_out_L1000_b_grad" input: "gpu_1/last_out_L1000_b_grad" input: "gpu_2/last_out_L1000_b_grad" input: "gpu_3/last_out_L1000_b_grad" output: "gpu_0/last_out_L1000_b_grad" output: "gpu_1/last_out_L1000_b_grad" output: "gpu_2/last_out_L1000_b_grad" output: "gpu_3/last_out_L1000_b_grad" name: "last_out_L1000_b_grad" type: "Allreduce" arg { name: "status_blob" s: "allreduce_last_out_L1000_b_grad_status" } arg { name: "gpu_direct" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "GLOO"
E0405 22:24:57.864006 24142 net_dag.cc:188] Secondary exception from operator chain starting at 'comp_15_spatbn_3_s_grad' (type 'Allreduce'): caffe2::EnforceNotMet: [enforce fail at context_gpu.h:155] . Encountered CUDA error: invalid resource handle Error from operator:
input: "allreduce_3_cw" input: "gpu_0/comp_15_spatbn_3_s_grad" input: "gpu_1/comp_15_spatbn_3_s_grad" input: "gpu_2/comp_15_spatbn_3_s_grad" input: "gpu_3/comp_15_spatbn_3_s_grad" output: "gpu_0/comp_15_spatbn_3_s_grad" output: "gpu_1/comp_15_spatbn_3_s_grad" output: "gpu_2/comp_15_spatbn_3_s_grad" output: "gpu_3/comp_15_spatbn_3_s_grad" name: "comp_15_spatbn_3_s_grad" type: "Allreduce" arg { name: "status_blob" s: "allreduce_comp_15_spatbn_3_s_grad_status" } arg { name: "gpu_direct" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "GLOO"
E0405 22:24:57.869789 24153 net_dag.cc:188] Secondary exception from operator chain starting at 'comp_15_spatbn_3_b_grad' (type 'Allreduce'): caffe2::EnforceNotMet: [enforce fail at context_gpu.h:155] . Encountered CUDA error: invalid resource handle Error from operator:
input: "allreduce_2_cw" input: "gpu_0/comp_15_spatbn_3_b_grad" input: "gpu_1/comp_15_spatbn_3_b_grad" input: "gpu_2/comp_15_spatbn_3_b_grad" input: "gpu_3/comp_15_spatbn_3_b_grad" output: "gpu_0/comp_15_spatbn_3_b_grad" output: "gpu_1/comp_15_spatbn_3_b_grad" output: "gpu_2/comp_15_spatbn_3_b_grad" output: "gpu_3/comp_15_spatbn_3_b_grad" name: "comp_15_spatbn_3_b_grad" type: "Allreduce" arg { name: "status_blob" s: "allreduce_comp_15_spatbn_3_b_grad_status" } arg { name: "gpu_direct" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "GLOO"
Original python traceback for operator 1752 in network resnet50 in exception above (most recent call last):
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 615, in
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 611, in main
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 434, in Train
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/data_parallel_model.py", line 271, in Parallelize
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/data_parallel_model.py", line 1149, in _AllReduceBlobs
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/data_parallel_model.py", line 1301, in _AllReduceBlobsDistributed
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/data_parallel_model.py", line 1292, in allreduce
Traceback (most recent call last):
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 615, in
main()
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 611, in main
Train(args)
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 529, in Train
explog
File "/root/caffe2/caffe2/python/examples/resnet50_trainer.py", line 175, in RunEpoch
workspace.RunNet(train_model.net.Proto().name)
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/workspace.py", line 215, in RunNet
StringifyNetName(name), num_iter, allow_fail,
File "/usr/local/lib/python2.7/dist-packages/caffe2/python/workspace.py", line 177, in CallWithExceptionIntercept
return func(*args, **kwargs)
RuntimeError: [enforce fail at context_gpu.h:155] . Encountered CUDA error: invalid resource handle Error from operator:
input: "allreduce_0_cw" input: "gpu_0/last_out_L1000_b_grad" input: "gpu_1/last_out_L1000_b_grad" input: "gpu_2/last_out_L1000_b_grad" input: "gpu_3/last_out_L1000_b_grad" output: "gpu_0/last_out_L1000_b_grad" output: "gpu_1/last_out_L1000_b_grad" output: "gpu_2/last_out_L1000_b_grad" output: "gpu_3/last_out_L1000_b_grad" name: "last_out_L1000_b_grad" type: "Allreduce" arg { name: "status_blob" s: "allreduce_last_out_L1000_b_grad_status" } arg { name: "gpu_direct" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "GLOO"

[bkovalev]

@pietern I can schedule with you Skype meeting and share my environment.

[pietern]

The warning in there doesn't look good. Can you double check the blobs are actually created?

E0405 22:24:40.959513 24032 operator.cc:463] Shape inference error: [enforce fail at conv_pool_op_base.h:601] in_size + *pad_head + *pad_tail >= dkernel. 2 vs 3
E0405 22:24:40.960314 24032 operator.cc:464] Operator: input: "gpu_0/conv1_spatbn_relu" output: "gpu_0/pool1" name: "" type: "MaxPool" arg { name: "order" s: "NCHW" } arg { name: "kernel" i: 3 } arg { name: "stride" i: 2 } arg { name: "ws_nbytes_limit" i: 67108864 } arg { name: "cudnn_exhaustive_search" i: 1 } device_option { device_type: 1 cuda_gpu_id: 0 } engine: "CUDNN"

[boriskovalev]

Hi now it's run ok with one GPU per node.
When I execute multi GPU per host with ibverb it's failed.
Distributed TCP and local multi GPUs is running ok.
The issue #6422 was opened.

[pietern]

Then I'll close this one and we can continue in #6422.