Torchserve_sanity script fails for MNIST models

[abishekchiffon]

Context

python torchserve_sanity.py fails for MNIST models in the gradle build inside a conda environment of a fresh ubuntu instance.
torchserve==0.2.0
torch-model-archiver==0.2.0

Python version: 3.8 (64-bit runtime)
Python executable: /home/ubuntu/anaconda3/envs/fbserve/bin/python3

Versions of relevant python libraries:
numpy==1.19.2
torch==1.4.0

Java Version:
openjdk 11.0.5 2019-10-15
OpenJDK Runtime Environment (build 11.0.5+10-post-Ubuntu-2ubuntu116.04)
OpenJDK 64-Bit Server VM (build 11.0.5+10-post-Ubuntu-2ubuntu116.04, mixed mode, sharing)

OS: Ubuntu 16.04.7 LTS
GCC version: (Ubuntu 5.4.0-6ubuntu1~16.04.12) 5.4.0 20160609

Your Environment

• Installed using source? [yes/no]: yes
• Are you planning to deploy it using docker container? [yes/no]: no
• Is it a CPU or GPU environment?: CPU
• Using a default/custom handler? [If possible upload/share custom handler/model]: NA
• What kind of model is it e.g. vision, text, audio?: vision
• Are you planning to use local models from model-store or public url being used e.g. from S3 bucket etc.?
  [If public url then provide link.]: NA
• Provide config.properties, logs [ts.log] and parameters used for model registration/update APIs: NA
• Link to your project [if any]: NA

Expected Behavior

The torchserve_sanity.py should pass for the master branch.

Current Behavior

It fails with the cases:

1) TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testLoadMNISTEagerModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1698
2) TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testPredictionMNISTEagerModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1727
3) TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testUnregistedMNISTEagerModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1650
4) TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testLoadMNISTScriptedModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1698

TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testPredictionMNISTScriptedModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1727
5)TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testUnregistedMNISTScriptedModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1650
6) TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testLoadMNISTTracedModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1698
7) TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testPredictionMNISTTracedModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1727

TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testUnregistedMNISTTracedModel STANDARD_OUT
    2020-11-25 15:03:48,323 [WARN ] epollEventLoopGroup-3-5 org.pytorch.serve.wlm.ModelManager - Model not found: mnist_traced
    2020-11-25 15:03:48,323 [INFO ] epollEventLoopGroup-3-5 ACCESS_LOG - /127.0.0.1:42678 "DELETE /models/mnist_traced HTTP/1.1" 404 0
    2020-11-25 15:03:48,323 [INFO ] epollEventLoopGroup-3-5 TS_METRICS - Requests4XX.Count:1|#Level:Host|#hostname:ip-172-31-61-118,timestamp:null

TorchServeSuite > TorchServe > org.pytorch.serve.ModelServerTest > testUnregistedMNISTTracedModel FAILED
    java.lang.AssertionError at ModelServerTest.java:1650

Steps to Reproduce

1. Install java jdk
2. Install the requirements as mentioned in the comment
3. Run python torchserve_sanit.py

Failure Logs [if any]

ec2_explain.log
master_ec2_c5_sanity_fail.log

[harshbafna]

@abishekchiffon: Looking at the logs, the unregister API call for MNIST model responded with 408 HTTP status which means the server was overloaded.

Could you share the machine configuration on which you tested this?

[abishekchiffon]

@abishekchiffon: Looking at the logs, the unregister API call for MNIST model responded with 408 HTTP status which means the server was overloaded.

Could you share the machine configuration on which you tested this?

I tested it on a t2.xlarge ec2 instance - 4cpus and 16GB RAM. The same happens in my local system, which is 4 cores and 8GB RAM.

[abishekchiffon]

@harshbafna I ran the torchserve_sanity.py after python ts_scripts/install_from_src.py on a c5n.9xlarge ec2 instance and I still get those Mnist errors.
I have attached the logs
master_ec2_c5_sanity_fail.log

[harshbafna]

@abishekchiffon: From the shared logs I observe the following error message:

import numpy as np
    2020-11-30 16:01:04,577 [INFO ] W-9055-mnist_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - ModuleNotFoundError: No module named 'numpy'

You need to run the following command to install the required dependencies:

python ts_scripts/install_dependencies.py

Refer following documentation for manual execution of test scripts:

https://github.com/pytorch/serve/blob/master/ts_scripts/Readme.md

[jeremiahschung]

Potentially related:

I encountered a failure running the testPredictionMNISTTracedModel test failing with an HTTP 503 error. In my case, this was due to a CUDA version mismatch between the environment vs the torch package. Installing the correct torch version resolved the issue for me.

2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Invoking custom service failed.
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Traceback (most recent call last):
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle -   File "/home/ubuntu/serve/ts/service.py", line 100, in predict
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle -     ret = self._entry_point(input_batch, self.context)
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle -   File "/tmp/models/a6e00db221d640d7af4841bf1f6636fa/mnist_handler.py", line 86, in handle
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle -     data = _service.inference(data)
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle -   File "/tmp/models/a6e00db221d640d7af4841bf1f6636fa/mnist_handler.py", line 65, in inference
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle -     outputs = self.model.forward(inputs)
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - RuntimeError: The following operation failed in the TorchScript interpreter.
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Traceback of TorchScript (most recent call last):
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - RuntimeError: The following operation failed in the TorchScript interpreter.
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Traceback of TorchScript (most recent call last):
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - RuntimeError: CUDA driver error: a PTX JIT compilation failed
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0 org.pytorch.serve.wlm.WorkerThread - Backend response time: 1397
2020-12-04 06:32:03,039 [INFO ] W-9022-mnist_traced_1.0 ACCESS_LOG - /127.0.0.1:34710 "POST /predictions/mnist_traced HTTP/1.1" 503 1398
2020-12-04 06:32:03,040 [INFO ] W-9022-mnist_traced_1.0 TS_METRICS - Requests5XX.Count:1|#Level:Host|#hostname:ip-172-31-20-44,timestamp:null

[harshbafna]

@jeremiahschung : Please share the torch and torchvision version.

[jeremiahschung]

@harshbafna
Here are the logs I was able to repro with!

Note that the machine (g4dn.xlarge on the Ubuntu 18.04 deep learning AMI) has CUDA 11 installed.

The test failed when the torch version was 1.6.0+cu92. Also note that the install_dependencies script fails to fetch the correct torch version for cu110.
fail_cuda_version_mismatch.txt

After manually updating torch/torchvision to 1.7.0/0.8.1+cu110, the test succeeds in the same machine.
succeess_correct_cuda_version.txt

[harshbafna]

@jeremiahschung: Please correct me if I am wrong, CUDA 11.0 support is available with Torch 1.7.0 only and not with Torch 1.6.0. The current master and 0.2.0 release are certified with Torch 1.6.0 only.

[jeremiahschung]

@harshbafna
Further looking into this, this looks like an issue with the PyTorch pip releases for torch 1.6.0. This still affects the latest TorchServe code and is not related to CUDA 11 or Torch 1.7 support.

Currently the command for installing torch 1.6.0 installs the binary for cu92 instead of cu102 which is an unexpected change in behavior.

ubuntu@ip-172-31-20-44:~/serve$ pip install torch==1.6.0 torchvision==0.7.0 -f https://download.pytorch.org/whl/torch_stable.html
Looking in links: https://download.pytorch.org/whl/torch_stable.html
Collecting torch==1.6.0
  Using cached https://download.pytorch.org/whl/cu92/torch-1.6.0%2Bcu92-cp37-cp37m-linux_x86_64.whl (552.8 MB)
Collecting torchvision==0.7.0
  Using cached https://download.pytorch.org/whl/cu92/torchvision-0.7.0%2Bcu92-cp37-cp37m-linux_x86_64.whl (5.8 MB)

I'll check with the PyTorch release team whether this is intended behavior or not.

Here's a repro in the current master code with the CUDA runtime switch to 10.2 as shown in this guide (nvcc -v shows 10.2 in the logs)
failure_cuda102_runtime.txt

As a workaround for now, we can change the torch_stable_url in ts_scripts/install_dependencies.py to include the specific cu102 path in the URL so that pip pulls the expected CUDA 10.2 torch binary. ex:

pip install -U torch==1.6.0 torchvision==0.7.0 -f https://download.pytorch.org/whl/cu102/torch_stable.html
Looking in links: https://download.pytorch.org/whl/cu102/torch_stable.html
Collecting torch==1.6.0
  Using cached torch-1.6.0-cp37-cp37m-manylinux1_x86_64.whl (748.8 MB)
Collecting torchvision==0.7.0
  Using cached torchvision-0.7.0-cp37-cp37m-manylinux1_x86_64.whl (5.9 MB)

Here's a successful run of the ts_scripts/test_frontend.py script after installing torch 1.6.0 for cu102:
success_cu102_install.txt

[maaquib]

@harshbafna

DLAMI 37; CU10.1; g4dn.xl

SUCCESS

> sudo ln -sf /usr/local/cuda-10.1 /usr/local/cuda
> ll /usr/local/cuda
lrwxrwxrwx 1 root root 20 Dec  4 19:21 /usr/local/cuda -> /usr/local/cuda-10.1/

> git clone https://github.com/pytorch/serve
> cd serve

> python ts_scripts/install_dependencies.py --cuda=cu101
> python ./ts_scripts/install_from_src.py
> python ./torchserve_sanity.py
> python test/regression_test.py

DLAMI 37; CU10.2; g4dn.xl

FAILURE: Same as reported by @jeremiahschung above

> sudo ln -sf /usr/local/cuda-10.2 /usr/local/cuda
> ll /usr/local/cuda
lrwxrwxrwx 1 root root 20 Dec  4 19:21 /usr/local/cuda -> /usr/local/cuda-10.2/

> git clone https://github.com/pytorch/serve
> cd serve

> python ts_scripts/install_dependencies.py
...
Collecting torch==1.6.0
  Downloading https://download.pytorch.org/whl/cu92/torch-1.6.0%2Bcu92-cp37-cp37m-linux_x86_64.whl (552.8 MB)
     |████████████████████████████████| 552.8 MB 95.6 MB/s eta 0:00:01
...
> python ./ts_scripts/install_from_src.py
> python ./torchserve_sanity.py
> python test/regression_test.py