search

pytorch / serve

Serve, optimize and scale PyTorch models in production
https://pytorch.org/serve/
Apache License 2.0
4.23k stars 864 forks source link

Handler to input/output wav file #1788

Closed Shin-ichi-Takayama closed 2 years ago

Shin-ichi-Takayama commented 2 years ago

I am asking again because the Issue(#1777 ) is not reopen. I have created a custom handler based on the documentation. However, it is not working well. Below is the procedure I have followed.

I have attempted to API the following inference code. This code removes noise from a wav file that is a mix of noise and voice. I used ESPnet as the noise removal tool.

from espnet2.bin.enh_inference import *
import soundfile

def main():
    separate_speech = SeparateSpeech("./train_enh_transformer_tf.yaml", "./valid.loss.best.pth")
    audio, rate = soundfile.read("Mix.wav")
    audio = audio[np.newaxis, :]
    separated_audio = separate_speech(audio)
    soundfile.write("separated.wav", separated_audio[0][0], rate, format="WAV", subtype="PCM_16")

if __name__ == "__main__":
    main()

So I created the following custom handlers.

# custom handler file

# model_handler.py

"""
ModelHandler defines a custom model handler.
"""
from espnet2.bin.enh_inference import *
import soundfile

from ts.torch_handler.base_handler import BaseHandler

class ModelHandler(BaseHandler):
    """
    A custom model handler implementation.
    """

    def __init__(self):
        self._context = None
        self.initialized = False
        self.model = None
        self.device = None

    def initialize(self, context):
        """
        Invoke by torchserve for loading a model
        :param context: context contains model server system properties
        :return:
        """

        #  load the model
        self.manifest = context.manifest

        properties = context.system_properties
        model_dir = properties.get("model_dir")
        self.device = torch.device("cuda:" + str(properties.get("gpu_id")) if torch.cuda.is_available() else "cpu")

        # Read model serialize/pt file
        serialized_file = self.manifest['model']['serializedFile']
        model_pt_path = os.path.join(model_dir, serialized_file)
        if not os.path.isfile(model_pt_path):
            raise RuntimeError("Missing the model.pt file")

        self.model = torch.jit.load(model_pt_path)

        self.initialized = True

    def preprocess(self,data):
        audio_data, rate  = soundfile.read(data)
        preprocessed_data = audio_data[np.newaxis, :]

        return preprocessed_data

    def inference(self, model_input):
        model_output = self.model.forward(model_input)
        return model_output

    def postprocess(self, inference_output):
        """
        Return inference result.
        :param inference_output: list of inference output
        :return: list of predict results
        """
        # Take output from network and post-process to desired format
        postprocess_output = inference_output
        #wav ni suru
        return postprocess_output

    def handle(self, data, context):
        model_input = self.preprocess(data)
        model_output = self.inference(model_input)
        return self.postprocess(model_output)

I created a mar file with the following command. The mar file was created in the specified folder.

root@e43b6b75eb45:~/transformer# torch-model-archiver --model-name denoise_transformer --version 1.0 --model-file /usr/local/lib/python3.6/dist-packages/espnet2/bin/enh_inference.py --serialized-file valid.loss.best.pth --export-path model_store --extra-files train_enh_transformer_tf.yaml --handler model_handler.py root@e43b6b75eb45:\~/transformer# cd model_store root@e43b6b75eb45:\~/transformer/model_store# ls -l total 39872 -rw-r--r-- 1 root root 40826112 Aug 3 08:41 denoise_transformer.mar

I started torchserve with the following command.

root@e43b6b75eb45:\~/transformer# torchserve --start --ncs --model-store model_store --models denoise_transformer=denoise_transformer.mar

I sent a wav file with the curl command.

root@e43b6b75eb45:\~# curl http://127.0.0.1:8080/predictions/denoise_transformer -T Mix.wav

However, the following response was received.

<HTML><HEAD>
<TITLE>Request Error</TITLE>
</HEAD>
<BODY>
<FONT face="Helvetica">
<big><strong></strong></big><BR>
</FONT>
<blockquote>
<TABLE border=0 cellPadding=1 width="80%">
<TR><TD>
<FONT face="Helvetica">
<big>Request Error (invalid_request)</big>
<BR>
<BR>
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica">
Your request could not be processed. Request could not be handled
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica">
This could be caused by a misconfiguration, or possibly a malformed request.
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica" SIZE=2>
<BR>
For assistance, contact your network support team.
</FONT>
</TD></TR>
</TABLE>
</blockquote>
</FONT>
</BODY></HTML>

Is there something wrong? I would appreciate your advice.

Best regards.

Shin-ichi-Takayama commented 2 years ago

The console log when starting torchserve is as follows.

root@e43b6b75eb45:\~/transformer# torchserve --start --ncs --model-store model_store --models denoise_transformer=denoise_transformer.mar root@e43b6b75eb45:~/transformer# WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. 2022-08-09T01:39:46,266 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Initializing plugins manager... 2022-08-09T01:39:46,471 [INFO ] main org.pytorch.serve.ModelServer - Torchserve version: 0.6.0 TS Home: /usr/local/lib/python3.8/dist-packages Current directory: /root/transformer Temp directory: /tmp Number of GPUs: 1 Number of CPUs: 16 Max heap size: 6384 M Python executable: /usr/bin/python3.8 Config file: N/A Inference address: http://127.0.0.1:8080 Management address: http://127.0.0.1:8081 Metrics address: http://127.0.0.1:8082 Model Store: /root/transformer/model_store Initial Models: denoise_transformer=denoise_transformer.mar Log dir: /root/transformer/logs Metrics dir: /root/transformer/logs Netty threads: 0 Netty client threads: 0 Default workers per model: 1 Blacklist Regex: N/A Maximum Response Size: 6553500 Maximum Request Size: 6553500 Limit Maximum Image Pixels: true Prefer direct buffer: false Allowed Urls: [file://.|http(s)?://.] Custom python dependency for model allowed: false Metrics report format: prometheus Enable metrics API: true Workflow Store: /root/transformer/model_store Model config: N/A 2022-08-09T01:39:46,477 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Loading snapshot serializer plugin... 2022-08-09T01:39:46,494 [INFO ] main org.pytorch.serve.ModelServer - Loading initial models: denoise_transformer.mar 2022-08-09T01:39:47,166 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Adding new version 1.0 for model denoise_transformer 2022-08-09T01:39:47,166 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Setting default version to 1.0 for model denoise_transformer 2022-08-09T01:39:47,167 [INFO ] main org.pytorch.serve.wlm.ModelManager - Model denoise_transformer loaded. 2022-08-09T01:39:47,167 [DEBUG] main org.pytorch.serve.wlm.ModelManager - updateModel: denoise_transformer, count: 1 2022-08-09T01:39:47,176 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3.8, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-09T01:39:47,177 [INFO ] main org.pytorch.serve.ModelServer - Initialize Inference server with: EpollServerSocketChannel. 2022-08-09T01:39:47,231 [INFO ] main org.pytorch.serve.ModelServer - Inference API bind to: http://127.0.0.1:8080 2022-08-09T01:39:47,231 [INFO ] main org.pytorch.serve.ModelServer - Initialize Management server with: EpollServerSocketChannel. 2022-08-09T01:39:47,233 [INFO ] main org.pytorch.serve.ModelServer - Management API bind to: http://127.0.0.1:8081 2022-08-09T01:39:47,234 [INFO ] main org.pytorch.serve.ModelServer - Initialize Metrics server with: EpollServerSocketChannel. 2022-08-09T01:39:47,235 [INFO ] main org.pytorch.serve.ModelServer - Metrics API bind to: http://127.0.0.1:8082 Model server started. 2022-08-09T01:39:47,467 [WARN ] pool-3-thread-1 org.pytorch.serve.metrics.MetricCollector - worker pid is not available yet. 2022-08-09T01:39:48,027 [INFO ] pool-3-thread-1 TS_METRICS - CPUUtilization.Percent:0.0|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,029 [INFO ] pool-3-thread-1 TS_METRICS - DiskAvailable.Gigabytes:198.68193435668945|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,030 [INFO ] pool-3-thread-1 TS_METRICS - DiskUsage.Gigabytes:39.484928131103516|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,030 [INFO ] pool-3-thread-1 TS_METRICS - DiskUtilization.Percent:16.6|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,030 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUtilization.Percent:19.44580078125|#Level:Host,device_id:0|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,031 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUsed.Megabytes:1593|#Level:Host,device_id:0|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,031 [INFO ] pool-3-thread-1 TS_METRICS - GPUUtilization.Percent:0|#Level:Host,device_id:0|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,031 [INFO ] pool-3-thread-1 TS_METRICS - MemoryAvailable.Megabytes:23667.22265625|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,031 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUsed.Megabytes:1461.78125|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,031 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUtilization.Percent:7.3|#Level:Host|#hostname:e43b6b75eb45,timestamp:1660009188 2022-08-09T01:39:48,031 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-09T01:39:48,033 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]5303 2022-08-09T01:39:48,033 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-09T01:39:48,033 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.0 2022-08-09T01:39:48,034 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change null -> WORKER_STARTED 2022-08-09T01:39:48,037 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-09T01:39:48,044 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-09T01:39:48,047 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660009188047 2022-08-09T01:39:48,081 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-09T01:39:48,083 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-09T01:39:48,084 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-09T01:39:48,084 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 100, in load 2022-08-09T01:39:48,084 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - module, function_name = self._load_handler_file(handler) 2022-08-09T01:39:48,085 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 162, in _load_handler_file 2022-08-09T01:39:48,085 [INFO ] epollEventLoopGroup-5-1 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-09T01:39:48,085 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - module = importlib.import_module(module_name) 2022-08-09T01:39:48,086 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/lib/python3.8/importlib/init.py", line 127, in import_module 2022-08-09T01:39:48,086 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-09T01:39:48,086 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - return _bootstrap._gcd_import(name[level:], package, level) 2022-08-09T01:39:48,086 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 1014, in _gcd_import 2022-08-09T01:39:48,086 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 991, in _find_and_load 2022-08-09T01:39:48,087 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 975, in _find_and_load_unlocked 2022-08-09T01:39:48,087 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 671, in _load_unlocked 2022-08-09T01:39:48,087 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 783, in exec_module 2022-08-09T01:39:48,088 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 219, in _call_with_frames_removed 2022-08-09T01:39:48,088 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/edb3f232862b4019a2f155b252bd2b37/model_handler.py", line 8, in 2022-08-09T01:39:48,088 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - from espnet2.bin.enh_inference import * 2022-08-09T01:39:48,088 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - ModuleNotFoundError: No module named 'espnet2' 2022-08-09T01:39:48,088 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - 2022-08-09T01:39:48,088 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - During handling of the above exception, another exception occurred: 2022-08-09T01:39:48,089 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - 2022-08-09T01:39:48,089 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-09T01:39:48,090 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-09T01:39:48,090 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-09T01:39:48,090 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-09T01:39:48,090 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-09T01:39:48,090 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-09T01:39:48,090 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-09T01:39:48,091 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-09T01:39:48,091 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-09T01:39:48,091 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 102, in load 2022-08-09T01:39:48,091 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - module = self._load_default_handler(handler) 2022-08-09T01:39:48,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 167, in _load_default_handler 2022-08-09T01:39:48,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - module = importlib.import_module(module_name, "ts.torch_handler") 2022-08-09T01:39:48,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/lib/python3.8/importlib/init.py", line 127, in import_module 2022-08-09T01:39:48,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - return _bootstrap._gcd_import(name[level:], package, level) 2022-08-09T01:39:48,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 1014, in _gcd_import 2022-08-09T01:39:48,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 991, in _find_and_load 2022-08-09T01:39:48,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 961, in _find_and_load_unlocked 2022-08-09T01:39:48,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 219, in _call_with_frames_removed 2022-08-09T01:39:48,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 1014, in _gcd_import 2022-08-09T01:39:48,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 991, in _find_and_load 2022-08-09T01:39:48,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 973, in _find_and_load_unlocked 2022-08-09T01:39:48,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - ModuleNotFoundError: No module named 'ts.torch_handler.model_handler' 2022-08-09T01:39:48,086 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056) ~[?:?] at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133) ~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:432) ~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:829) [?:?] 2022-08-09T01:39:48,099 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.BatchAggregator - Load model failed: denoise_transformer, error: Worker died. 2022-08-09T01:39:48,099 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_STOPPED 2022-08-09T01:39:48,100 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stderr 2022-08-09T01:39:48,100 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stdout 2022-08-09T01:39:48,100 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Retry worker: 9000 in 1 seconds. 2022-08-09T01:39:48,108 [INFO ] W-9000-denoise_transformer_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stdout 2022-08-09T01:39:48,108 [INFO ] W-9000-denoise_transformer_1.0-stderr org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stderr 2022-08-09T01:39:49,102 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3.8, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-09T01:39:49,526 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-09T01:39:49,527 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]5358 2022-08-09T01:39:49,527 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-09T01:39:49,527 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STOPPED -> WORKER_STARTED 2022-08-09T01:39:49,527 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.0 2022-08-09T01:39:49,527 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-09T01:39:49,530 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-09T01:39:49,530 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660009189530 2022-08-09T01:39:49,535 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-09T01:39:49,536 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-09T01:39:49,536 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-09T01:39:49,537 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 100, in load 2022-08-09T01:39:49,537 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - module, function_name = self._load_handler_file(handler) 2022-08-09T01:39:49,537 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 162, in _load_handler_file 2022-08-09T01:39:49,537 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - module = importlib.import_module(module_name) 2022-08-09T01:39:49,537 [INFO ] epollEventLoopGroup-5-2 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-09T01:39:49,537 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/lib/python3.8/importlib/init.py", line 127, in import_module 2022-08-09T01:39:49,537 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - return _bootstrap._gcd_import(name[level:], package, level) 2022-08-09T01:39:49,538 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-09T01:39:49,538 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 1014, in _gcd_import 2022-08-09T01:39:49,538 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 991, in _find_and_load 2022-08-09T01:39:49,538 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "", line 975, in _find_and_load_unlocked 2022-08-09T01:39:49,538 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056) ~[?:?] at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2133) ~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:432) ~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:829) [?:?]

maaquib commented 2 years ago

@Shin-ichi-Takayama Looking at the logs, it seems like you have not installed espnet2. ModuleNotFoundError: No module named 'espnet2'

Shin-ichi-Takayama commented 2 years ago

Thanks for your reply.

Looking at the logs, it seems like you have not installed espnet2.

However, I am able to run the following code importing espnet2.

from espnet2.bin.enh_inference import *
import soundfile

def main():
    separate_speech = SeparateSpeech("./train_enh_transformer_tf.yaml", "./valid.loss.best.pth")
    audio, rate = soundfile.read("Mix.wav")
    audio = audio[np.newaxis, :]
    separated_audio = separate_speech(audio)
    soundfile.write("separated.wav", separated_audio[0][0], rate, format="WAV", subtype="PCM_16")

if __name__ == "__main__":
    main()

I checked the library with the pip list command. espnet was installed.

root@f45ba30475c5:~/torchserve# pip list Package Version ------------------- -------------------- appdirs 1.4.4 audioread 2.1.9 captum 0.5.0 certifi 2019.11.28 cffi 1.15.1 chardet 3.0.4 ci-sdr 0.0.0 click 8.1.3 ConfigArgParse 1.5.3 ctc-segmentation 1.7.1 cycler 0.11.0 Cython 0.29.32 dbus-python 1.2.16 decorator 5.1.1 Distance 0.1.3 distro-info 0.23ubuntu1 einops 0.4.1 espnet 202207 espnet-tts-frontend 0.0.3 fast-bss-eval 0.1.3 filelock 3.8.0 fonttools 4.34.4 future 0.18.2 g2p-en 2.1.0 h5py 3.7.0 huggingface-hub 0.8.1 humanfriendly 10.0 idna 2.8 importlib-metadata 4.12.0 inflect 6.0.0 jaconv 0.3 jamo 0.4.1 joblib 1.1.0 kaldiio 2.17.2 kiwisolver 1.4.4 librosa 0.9.2 llvmlite 0.39.0 matplotlib 3.5.2 nltk 3.7 numba 0.56.0 numpy 1.22.0 packaging 21.3 Pillow 9.2.0 pip 22.2.2 pooch 1.6.0 protobuf 3.20.1 psutil 5.9.1 pycparser 2.21 pydantic 1.9.1 PyGObject 3.36.0 pyparsing 3.0.9 pypinyin 0.44.0 python-apt 2.0.0+ubuntu0.20.4.7 python-dateutil 2.8.2 pytorch-wpe 0.0.1 pyworld 0.3.0 PyYAML 6.0 regex 2022.7.25 requests 2.22.0 requests-unixsocket 0.2.0 resampy 0.4.0 scikit-learn 1.1.2 scipy 1.9.0 sentencepiece 0.1.97 setuptools 63.4.2 six 1.14.0 SoundFile 0.10.3.post1 threadpoolctl 3.1.0 tokenizers 0.12.1 torch 1.7.1 torch-complex 0.4.3 torchaudio 0.7.2 torchtext 0.8.1 torchvision 0.8.2 tqdm 4.64.0 transformers 4.21.1 typeguard 2.13.3 typing_extensions 4.3.0 unattended-upgrades 0.1 Unidecode 1.3.4 urllib3 1.25.8 wheel 0.34.2 zipp 3.8.1

maaquib commented 2 years ago

@Shin-ichi-Takayama Can you also confirm if the python executable being used by Torchserve /usr/bin/python3.8 is the same as the on you are checking the pip list for?

Shin-ichi-Takayama commented 2 years ago

@maaquib Thanks for your reply.

I built the environment again. I was able to see espnet and torchserve in the pip list. I think they refer to the same Python.

root@09e4b7373d58:~/torchserve/files# pip list Package Version -------------------- -------------------- aniso8601 9.0.1 ansi2html 1.8.0 appdirs 1.4.4 arrow 1.2.2 audioread 2.1.9 certifi 2019.11.28 cffi 1.15.1 chardet 3.0.4 ci-sdr 0.0.0 click 8.1.3 ConfigArgParse 1.5.3 ctc-segmentation 1.7.1 Cython 0.29.32 dbus-python 1.2.16 decorator 5.1.1 Distance 0.1.3 distro-info 0.23ubuntu1 einops 0.4.1 enum-compat 0.0.3 espnet 202207 espnet-tts-frontend 0.0.3 fast-bss-eval 0.1.3 filelock 3.8.0 Flask 2.2.2 Flask-RESTful 0.3.9 future 0.18.2 g2p-en 2.1.0 h5py 3.7.0 humanfriendly 10.0 idna 2.8 importlib-metadata 4.12.0 inflect 6.0.0 itsdangerous 2.1.2 jaconv 0.3 jamo 0.4.1 Jinja2 3.1.2 joblib 1.1.0 kaldiio 2.17.2 librosa 0.9.2 llvmlite 0.39.0 MarkupSafe 2.1.1 nltk 3.7 numba 0.56.0 numpy 1.22.0 nvgpu 0.9.0 packaging 21.3 pandas 1.4.3 Pillow 9.2.0 pip 22.2.2 pooch 1.6.0 protobuf 3.20.1 psutil 5.9.1 pycparser 2.21 pydantic 1.9.2 PyGObject 3.36.0 pynvml 11.4.1 pyparsing 3.0.9 pypinyin 0.44.0 python-apt 2.0.0+ubuntu0.20.4.7 python-dateutil 2.8.2 pytorch-wpe 0.0.1 pytz 2022.2.1 pyworld 0.3.0 PyYAML 6.0 regex 2022.7.25 requests 2.22.0 requests-unixsocket 0.2.0 resampy 0.4.0 scikit-learn 1.1.2 scipy 1.9.0 sentencepiece 0.1.97 setuptools 64.0.1 six 1.14.0 SoundFile 0.10.3.post1 tabulate 0.8.10 termcolor 1.1.0 threadpoolctl 3.1.0 torch 1.12.1 torch-complex 0.4.3 torch-model-archiver 0.6.0 torchserve 0.6.0 torchtext 0.13.1 torchvision 0.13.1 tqdm 4.64.0 typeguard 2.13.3 typing_extensions 4.3.0 unattended-upgrades 0.1 Unidecode 1.3.4 urllib3 1.25.8 Werkzeug 2.2.2 wheel 0.34.2 zipp 3.8.1

I tried torchserve again and it is still not working correctly. When I run the curl command, it returns the following error.

<HTML><HEAD>
<TITLE>Request Error</TITLE>
</HEAD>
<BODY>
<FONT face="Helvetica">
<big><strong></strong></big><BR>
</FONT>
<blockquote>
<TABLE border=0 cellPadding=1 width="80%">
<TR><TD>
<FONT face="Helvetica">
<big>Request Error (invalid_request)</big>
<BR>
<BR>
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica">
Your request could not be processed. Request could not be handled
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica">
This could be caused by a misconfiguration, or possibly a malformed request.
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica" SIZE=2>
<BR>
For assistance, contact your network support team.
</FONT>
</TD></TR>
</TABLE>
</blockquote>
</FONT>
</BODY></HTML>

The following logs are output to the console.

root@09e4b7373d58:~/torchserve/files# WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. 2022-08-13T11:44:31,478 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Initializing plugins manager... 2022-08-13T11:44:31,631 [INFO ] main org.pytorch.serve.ModelServer - Torchserve version: 0.6.0 TS Home: /usr/local/lib/python3.8/dist-packages Current directory: /root/torchserve/files Temp directory: /tmp Number of GPUs: 1 Number of CPUs: 16 Max heap size: 1990 M Python executable: /usr/bin/python3 Config file: N/A Inference address: http://127.0.0.1:8080 Management address: http://127.0.0.1:8081 Metrics address: http://127.0.0.1:8082 Model Store: /root/torchserve/files/model_store Initial Models: denoise_transformer=denoise_transformer.mar Log dir: /root/torchserve/files/logs Metrics dir: /root/torchserve/files/logs Netty threads: 0 Netty client threads: 0 Default workers per model: 1 Blacklist Regex: N/A Maximum Response Size: 6553500 Maximum Request Size: 6553500 Limit Maximum Image Pixels: true Prefer direct buffer: false Allowed Urls: [file://.|http(s)?://.] Custom python dependency for model allowed: false Metrics report format: prometheus Enable metrics API: true Workflow Store: /root/torchserve/files/model_store Model config: N/A 2022-08-13T11:44:31,639 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Loading snapshot serializer plugin... 2022-08-13T11:44:31,651 [INFO ] main org.pytorch.serve.ModelServer - Loading initial models: denoise_transformer.mar 2022-08-13T11:44:31,984 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Adding new version 1.0 for model denoise_transformer 2022-08-13T11:44:31,984 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Setting default version to 1.0 for model denoise_transformer 2022-08-13T11:44:31,985 [INFO ] main org.pytorch.serve.wlm.ModelManager - Model denoise_transformer loaded. 2022-08-13T11:44:31,985 [DEBUG] main org.pytorch.serve.wlm.ModelManager - updateModel: denoise_transformer, count: 1 2022-08-13T11:44:31,990 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-13T11:44:31,991 [INFO ] main org.pytorch.serve.ModelServer - Initialize Inference server with: EpollServerSocketChannel. 2022-08-13T11:44:32,025 [INFO ] main org.pytorch.serve.ModelServer - Inference API bind to: http://127.0.0.1:8080 2022-08-13T11:44:32,025 [INFO ] main org.pytorch.serve.ModelServer - Initialize Management server with: EpollServerSocketChannel. 2022-08-13T11:44:32,026 [INFO ] main org.pytorch.serve.ModelServer - Management API bind to: http://127.0.0.1:8081 2022-08-13T11:44:32,027 [INFO ] main org.pytorch.serve.ModelServer - Initialize Metrics server with: EpollServerSocketChannel. 2022-08-13T11:44:32,027 [INFO ] main org.pytorch.serve.ModelServer - Metrics API bind to: http://127.0.0.1:8082 Model server started. 2022-08-13T11:44:32,199 [WARN ] pool-3-thread-1 org.pytorch.serve.metrics.MetricCollector - worker pid is not available yet. 2022-08-13T11:44:32,443 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T11:44:32,444 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]3672 2022-08-13T11:44:32,445 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T11:44:32,445 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T11:44:32,445 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change null -> WORKER_STARTED 2022-08-13T11:44:32,448 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T11:44:32,454 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T11:44:32,455 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660358672455 2022-08-13T11:44:32,472 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-13T11:44:32,513 [INFO ] pool-3-thread-1 TS_METRICS - CPUUtilization.Percent:0.0|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,513 [INFO ] pool-3-thread-1 TS_METRICS - DiskAvailable.Gigabytes:228.6658592224121|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,514 [INFO ] pool-3-thread-1 TS_METRICS - DiskUsage.Gigabytes:9.50100326538086|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,514 [INFO ] pool-3-thread-1 TS_METRICS - DiskUtilization.Percent:4.0|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,514 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUtilization.Percent:14.0625|#Level:Host,device_id:0|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,515 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUsed.Megabytes:1152|#Level:Host,device_id:0|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,515 [INFO ] pool-3-thread-1 TS_METRICS - GPUUtilization.Percent:5|#Level:Host,device_id:0|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,515 [INFO ] pool-3-thread-1 TS_METRICS - MemoryAvailable.Megabytes:6400.125|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,515 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUsed.Megabytes:1259.4765625|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:32,516 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUtilization.Percent:19.5|#Level:Host|#hostname:09e4b7373d58,timestamp:1660358672 2022-08-13T11:44:33,228 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-13T11:44:33,228 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-13T11:44:33,229 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-13T11:44:33,229 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-13T11:44:33,229 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-13T11:44:33,229 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-13T11:44:33,229 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-13T11:44:33,230 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-13T11:44:33,230 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-13T11:44:33,230 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-13T11:44:33,231 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 151, in load 2022-08-13T11:44:33,231 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - initialize_fn(service.context) 2022-08-13T11:44:33,231 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/b9e0ef76048c4516a4fe3871006f6828/model_handler.py", line 40, in initialize 2022-08-13T11:44:33,231 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_pt_path = os.path.join(model_dir, serialized_file) 2022-08-13T11:44:33,231 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - NameError: name 'os' is not defined 2022-08-13T11:44:33,312 [INFO ] epollEventLoopGroup-5-1 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-13T11:44:33,313 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-13T11:44:33,313 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1679) ~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435) ~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] 2022-08-13T11:44:33,322 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.BatchAggregator - Load model failed: denoise_transformer, error: Worker died. 2022-08-13T11:44:33,322 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_STOPPED 2022-08-13T11:44:33,323 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stderr 2022-08-13T11:44:33,323 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stdout 2022-08-13T11:44:33,324 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Retry worker: 9000 in 1 seconds. 2022-08-13T11:44:33,334 [INFO ] W-9000-denoise_transformer_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stdout 2022-08-13T11:44:33,334 [INFO ] W-9000-denoise_transformer_1.0-stderr org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stderr 2022-08-13T11:44:34,327 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-13T11:44:34,721 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T11:44:34,722 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]3735 2022-08-13T11:44:34,722 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T11:44:34,722 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STOPPED -> WORKER_STARTED 2022-08-13T11:44:34,722 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T11:44:34,722 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T11:44:34,724 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660358674724 2022-08-13T11:44:34,724 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T11:44:34,728 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-13T11:44:35,538 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-13T11:44:35,538 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-13T11:44:35,539 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-13T11:44:35,539 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-13T11:44:35,539 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-13T11:44:35,539 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-13T11:44:35,539 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-13T11:44:35,539 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-13T11:44:35,540 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-13T11:44:35,540 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-13T11:44:35,540 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 151, in load 2022-08-13T11:44:35,540 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - initialize_fn(service.context) 2022-08-13T11:44:35,540 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/b9e0ef76048c4516a4fe3871006f6828/model_handler.py", line 40, in initialize 2022-08-13T11:44:35,540 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_pt_path = os.path.join(model_dir, serialized_file) 2022-08-13T11:44:35,541 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - NameError: name 'os' is not defined 2022-08-13T11:44:35,623 [INFO ] epollEventLoopGroup-5-2 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-13T11:44:35,624 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-13T11:44:35,624 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1679) ~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435) ~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] 2022-08-13T11:44:35,624 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.BatchAggregator - Load model failed: denoise_transformer, error: Worker died. 2022-08-13T11:44:35,625 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_STOPPED 2022-08-13T11:44:35,625 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stderr 2022-08-13T11:44:35,625 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stdout 2022-08-13T11:44:35,625 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Retry worker: 9000 in 1 seconds. 2022-08-13T11:44:35,637 [INFO ] W-9000-denoise_transformer_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stdout 2022-08-13T11:44:35,637 [INFO ] W-9000-denoise_transformer_1.0-stderr org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stderr 2022-08-13T11:44:36,627 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] ^C root@09e4b7373d58:\~/torchserve/files# 2022-08-13T11:44:37,013 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T11:44:37,013 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]3771 2022-08-13T11:44:37,013 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T11:44:37,013 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STOPPED -> WORKER_STARTED 2022-08-13T11:44:37,013 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T11:44:37,014 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T11:44:37,015 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T11:44:37,015 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660358677015 2022-08-13T11:44:37,019 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-13T11:44:37,766 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-13T11:44:37,767 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 151, in load 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - initialize_fn(service.context) 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/b9e0ef76048c4516a4fe3871006f6828/model_handler.py", line 40, in initialize 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_pt_path = os.path.join(model_dir, serialized_file) 2022-08-13T11:44:37,768 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - NameError: name 'os' is not defined 2022-08-13T11:44:37,850 [INFO ] epollEventLoopGroup-5-3 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-13T11:44:37,851 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-13T11:44:37,851 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1679) \~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435) \~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] 2022-08-13T11:44:37,852 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.BatchAggregator - Load model failed: denoise_transformer, error: Worker died. 2022-08-13T11:44:37,852 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_STOPPED 2022-08-13T11:44:37,852 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stderr 2022-08-13T11:44:37,852 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stdout 2022-08-13T11:44:37,852 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Retry worker: 9000 in 2 seconds. 2022-08-13T11:44:37,863 [INFO ] W-9000-denoise_transformer_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stdout 2022-08-13T11:44:37,863 [INFO ] W-9000-denoise_transformer_1.0-stderr org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stderr 2022-08-13T11:44:39,853 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-13T11:44:40,303 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T11:44:40,304 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]3810 2022-08-13T11:44:40,304 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T11:44:40,304 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STOPPED -> WORKER_STARTED 2022-08-13T11:44:40,304 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T11:44:40,304 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T11:44:40,305 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660358680305 2022-08-13T11:44:40,305 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T11:44:40,324 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-13T11:44:41,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-13T11:44:41,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-13T11:44:41,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-13T11:44:41,092 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 151, in load 2022-08-13T11:44:41,093 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - initialize_fn(service.context) 2022-08-13T11:44:41,094 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/b9e0ef76048c4516a4fe3871006f6828/model_handler.py", line 40, in initialize 2022-08-13T11:44:41,094 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_pt_path = os.path.join(model_dir, serialized_file) 2022-08-13T11:44:41,094 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - NameError: name 'os' is not defined 2022-08-13T11:44:41,179 [INFO ] epollEventLoopGroup-5-4 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-13T11:44:41,179 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-13T11:44:41,179 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died.

Best regards.

Shin-ichi-Takayama commented 2 years ago

I was getting an error "NameError: name 'os' is not defined", so I added "import os" to the model_handler.py file. The log changed as follows.

root@09e4b7373d58:\~/torchserve/files# WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance. 2022-08-13T13:30:12,959 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Initializing plugins manager... 2022-08-13T13:30:13,097 [INFO ] main org.pytorch.serve.ModelServer - Torchserve version: 0.6.0 TS Home: /usr/local/lib/python3.8/dist-packages Current directory: /root/torchserve/files Temp directory: /tmp Number of GPUs: 1 Number of CPUs: 16 Max heap size: 1990 M Python executable: /usr/bin/python3 Config file: N/A Inference address: http://127.0.0.1:8080 Management address: http://127.0.0.1:8081 Metrics address: http://127.0.0.1:8082 Model Store: /root/torchserve/files/model_store Initial Models: denoise_transformer=denoise_transformer.mar Log dir: /root/torchserve/files/logs Metrics dir: /root/torchserve/files/logs Netty threads: 0 Netty client threads: 0 Default workers per model: 1 Blacklist Regex: N/A Maximum Response Size: 6553500 Maximum Request Size: 6553500 Limit Maximum Image Pixels: true Prefer direct buffer: false Allowed Urls: [file://.|http(s)?://.] Custom python dependency for model allowed: false Metrics report format: prometheus Enable metrics API: true Workflow Store: /root/torchserve/files/model_store Model config: N/A 2022-08-13T13:30:13,105 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Loading snapshot serializer plugin... 2022-08-13T13:30:13,117 [INFO ] main org.pytorch.serve.ModelServer - Loading initial models: denoise_transformer.mar 2022-08-13T13:30:13,458 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Adding new version 1.0 for model denoise_transformer 2022-08-13T13:30:13,458 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Setting default version to 1.0 for model denoise_transformer 2022-08-13T13:30:13,458 [INFO ] main org.pytorch.serve.wlm.ModelManager - Model denoise_transformer loaded. 2022-08-13T13:30:13,459 [DEBUG] main org.pytorch.serve.wlm.ModelManager - updateModel: denoise_transformer, count: 1 2022-08-13T13:30:13,464 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-13T13:30:13,464 [INFO ] main org.pytorch.serve.ModelServer - Initialize Inference server with: EpollServerSocketChannel. 2022-08-13T13:30:13,500 [INFO ] main org.pytorch.serve.ModelServer - Inference API bind to: http://127.0.0.1:8080 2022-08-13T13:30:13,500 [INFO ] main org.pytorch.serve.ModelServer - Initialize Management server with: EpollServerSocketChannel. 2022-08-13T13:30:13,501 [INFO ] main org.pytorch.serve.ModelServer - Management API bind to: http://127.0.0.1:8081 2022-08-13T13:30:13,502 [INFO ] main org.pytorch.serve.ModelServer - Initialize Metrics server with: EpollServerSocketChannel. 2022-08-13T13:30:13,503 [INFO ] main org.pytorch.serve.ModelServer - Metrics API bind to: http://127.0.0.1:8082 Model server started. 2022-08-13T13:30:13,656 [WARN ] pool-3-thread-1 org.pytorch.serve.metrics.MetricCollector - worker pid is not available yet. 2022-08-13T13:30:13,922 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T13:30:13,924 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]4463 2022-08-13T13:30:13,924 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T13:30:13,924 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T13:30:13,924 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change null -> WORKER_STARTED 2022-08-13T13:30:13,928 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T13:30:13,933 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T13:30:13,934 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660365013934 2022-08-13T13:30:13,951 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-13T13:30:13,995 [INFO ] pool-3-thread-1 TS_METRICS - CPUUtilization.Percent:0.0|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,996 [INFO ] pool-3-thread-1 TS_METRICS - DiskAvailable.Gigabytes:228.66552352905273|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,996 [INFO ] pool-3-thread-1 TS_METRICS - DiskUsage.Gigabytes:9.501338958740234|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,996 [INFO ] pool-3-thread-1 TS_METRICS - DiskUtilization.Percent:4.0|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,996 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUtilization.Percent:14.68505859375|#Level:Host,device_id:0|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,997 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUsed.Megabytes:1203|#Level:Host,device_id:0|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,997 [INFO ] pool-3-thread-1 TS_METRICS - GPUUtilization.Percent:3|#Level:Host,device_id:0|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,997 [INFO ] pool-3-thread-1 TS_METRICS - MemoryAvailable.Megabytes:6364.30078125|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,997 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUsed.Megabytes:1295.546875|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:13,998 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUtilization.Percent:20.0|#Level:Host|#hostname:09e4b7373d58,timestamp:1660365013 2022-08-13T13:30:14,699 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-13T13:30:14,699 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-13T13:30:14,700 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-13T13:30:14,700 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-13T13:30:14,700 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-13T13:30:14,700 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-13T13:30:14,700 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-13T13:30:14,701 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-13T13:30:14,701 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-13T13:30:14,701 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-13T13:30:14,702 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 151, in load 2022-08-13T13:30:14,702 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - initialize_fn(service.context) 2022-08-13T13:30:14,702 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/cf701b88f4bf46348d6fb5fe102cb6de/model_handler.py", line 45, in initialize 2022-08-13T13:30:14,702 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.model = torch.jit.load(model_pt_path) 2022-08-13T13:30:14,702 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/torch/jit/_serialization.py", line 162, in load 2022-08-13T13:30:14,703 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - cpp_module = torch._C.import_ir_module(cu, str(f), map_location, _extra_files) 2022-08-13T13:30:14,703 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - RuntimeError: PytorchStreamReader failed locating file constants.pkl: file not found 2022-08-13T13:30:14,788 [INFO ] epollEventLoopGroup-5-1 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-13T13:30:14,789 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-13T13:30:14,789 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1679) \~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435) \~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] 2022-08-13T13:30:14,797 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.BatchAggregator - Load model failed: denoise_transformer, error: Worker died. 2022-08-13T13:30:14,797 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_STOPPED 2022-08-13T13:30:14,797 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stderr 2022-08-13T13:30:14,797 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stdout 2022-08-13T13:30:14,798 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Retry worker: 9000 in 1 seconds. 2022-08-13T13:30:14,810 [INFO ] W-9000-denoise_transformer_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stdout 2022-08-13T13:30:14,810 [INFO ] W-9000-denoise_transformer_1.0-stderr org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stderr 2022-08-13T13:30:15,800 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-13T13:30:16,188 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T13:30:16,189 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]4526 2022-08-13T13:30:16,189 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T13:30:16,189 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STOPPED -> WORKER_STARTED 2022-08-13T13:30:16,189 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T13:30:16,189 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T13:30:16,191 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T13:30:16,191 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660365016191 2022-08-13T13:30:16,199 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1 2022-08-13T13:30:16,988 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Backend worker process died. 2022-08-13T13:30:16,988 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Traceback (most recent call last): 2022-08-13T13:30:16,989 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 210, in 2022-08-13T13:30:16,989 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - worker.run_server() 2022-08-13T13:30:16,989 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 181, in run_server 2022-08-13T13:30:16,989 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.handle_connection(cl_socket) 2022-08-13T13:30:16,990 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 139, in handle_connection 2022-08-13T13:30:16,990 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service, result, code = self.load_model(msg) 2022-08-13T13:30:16,990 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py", line 104, in load_model 2022-08-13T13:30:16,990 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - service = model_loader.load( 2022-08-13T13:30:16,990 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/ts/model_loader.py", line 151, in load 2022-08-13T13:30:16,991 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - initialize_fn(service.context) 2022-08-13T13:30:16,991 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/tmp/models/cf701b88f4bf46348d6fb5fe102cb6de/model_handler.py", line 45, in initialize 2022-08-13T13:30:16,991 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - self.model = torch.jit.load(model_pt_path) 2022-08-13T13:30:16,992 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - File "/usr/local/lib/python3.8/dist-packages/torch/jit/_serialization.py", line 162, in load 2022-08-13T13:30:16,992 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - cpp_module = torch._C.import_ir_module(cu, str(f), map_location, _extra_files) 2022-08-13T13:30:16,992 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - RuntimeError: PytorchStreamReader failed locating file constants.pkl: file not found 2022-08-13T13:30:17,076 [INFO ] epollEventLoopGroup-5-2 org.pytorch.serve.wlm.WorkerThread - 9000 Worker disconnected. WORKER_STARTED 2022-08-13T13:30:17,077 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - System state is : WORKER_STARTED 2022-08-13T13:30:17,077 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend worker monitoring thread interrupted or backend worker process died. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1679) ~[?:?] at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435) ~[?:?] at org.pytorch.serve.wlm.WorkerThread.run(WorkerThread.java:189) [model-server.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] 2022-08-13T13:30:17,077 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.BatchAggregator - Load model failed: denoise_transformer, error: Worker died. 2022-08-13T13:30:17,077 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_STOPPED 2022-08-13T13:30:17,078 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stderr 2022-08-13T13:30:17,078 [WARN ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - terminateIOStreams() threadName=W-9000-denoise_transformer_1.0-stdout 2022-08-13T13:30:17,078 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Retry worker: 9000 in 1 seconds. 2022-08-13T13:30:17,089 [INFO ] W-9000-denoise_transformer_1.0-stdout org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stdout 2022-08-13T13:30:17,089 [INFO ] W-9000-denoise_transformer_1.0-stderr org.pytorch.serve.wlm.WorkerLifeCycle - Stopped Scanner - W-9000-denoise_transformer_1.0-stderr torchserve --stop2022-08-13T13:30:18,080 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000] 2022-08-13T13:30:18,464 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000 2022-08-13T13:30:18,465 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]4562 2022-08-13T13:30:18,465 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started. 2022-08-13T13:30:18,465 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STOPPED -> WORKER_STARTED 2022-08-13T13:30:18,465 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10 2022-08-13T13:30:18,465 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000 2022-08-13T13:30:18,466 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000. 2022-08-13T13:30:18,467 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1660365018466 2022-08-13T13:30:18,470 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1

maaquib commented 2 years ago

From the logs it seems like it is missing a file to load

2022-08-13T13:30:14,703 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - RuntimeError: PytorchStreamReader failed locating file constants.pkl: file not found
Shin-ichi-Takayama commented 2 years ago

@maaquib Thank you for your reply.

I am not using the constants.pkl file. I do not include it in the source of my custom handlers. Are you saying that the constants.pkl is being used somewhere?

Shin-ichi-Takayama commented 2 years ago

@maaquib The custom handler has been modified as follows

# custom handler file

# model_handler.py

"""
ModelHandler defines a custom model handler.
"""
import os
import soundfile
from espnet2.bin.enh_inference import *

from ts.torch_handler.base_handler import BaseHandler

class ModelHandler(BaseHandler):
    """
    A custom model handler implementation.
    """

    def __init__(self):
        self._context = None
        self.initialized = False
        self.model = None
        self.device = None

    def initialize(self, context):
        """
        Invoke by torchserve for loading a model
        :param context: context contains model server system properties
        :return:
        """

        #  load the model
        self.manifest = context.manifest

        properties = context.system_properties
        model_dir = properties.get("model_dir")
        self.device = torch.device("cuda:" + str(properties.get("gpu_id")) if torch.cuda.is_available() else "cpu")

        # Read model serialize/pt file
        serialized_file = self.manifest['model']['serializedFile']
        model_pt_path = os.path.join(model_dir, serialized_file)

        if not os.path.isfile(model_pt_path):
            raise RuntimeError("Missing the model.pt file")

        self.model = SeparateSpeech("train_enh_transformer_tf.yaml", "valid.loss.best.pth")

        self.initialized = True

    def preprocess(self,data):
        audio_data, rate  = soundfile.read(data)
        preprocessed_data = audio_data[np.newaxis, :]

        return preprocessed_data

    def inference(self, model_input):
        model_output = self.model(model_input)
        return model_output
    def postprocess(self, inference_output):
        """
        Return inference result.
        :param inference_output: list of inference output
        :return: list of predict results
        """
        # Take output from network and post-process to desired format
        postprocess_output = inference_output
        #wav ni suru
        return postprocess_output

    def handle(self, data, context):
        model_input = self.preprocess(data)
        model_output = self.inference(model_input)
        return self.postprocess(model_output)

After modifying the model load process, the error is gone. The error is gone and torchserve appears to be working.

I sent the wav file to torchserve with the following command

curl http://127.0.0.1:8080/predictions/denoise_transformer -T Mix.wav

However, the following error was returned

<HTML><HEAD>
<TITLE>Request Error</TITLE>
</HEAD>
<BODY>
<FONT face="Helvetica">
<big><strong></strong></big><BR>
</FONT>
<blockquote>
<TABLE border=0 cellPadding=1 width="80%">
<TR><TD>
<FONT face="Helvetica">
<big>Request Error (invalid_request)</big>
<BR>
<BR>
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica">
Your request could not be processed. Request could not be handled
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica">
This could be caused by a misconfiguration, or possibly a malformed request.
</FONT>
</TD></TR>
<TR><TD>
<FONT face="Helvetica" SIZE=2>
<BR>
For assistance, contact your network support team.
</FONT>
</TD></TR>
</TABLE>
</blockquote>
</FONT>
</BODY></HTML>

The Torchserve logs are as follows

root@5c780ba74916:~/files# torchserve --start --ncs --model-store model_store --models denoise_transformer=denoise_transformer.mar
root@5c780ba74916:~/files# WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
2022-08-24T14:06:06,662 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager - Initializing plugins manager...
2022-08-24T14:06:06,796 [INFO ] main org.pytorch.serve.ModelServer -
Torchserve version: 0.6.0
TS Home: /usr/local/lib/python3.8/dist-packages
Current directory: /root/files
Temp directory: /tmp
Number of GPUs: 1
Number of CPUs: 16
Max heap size: 4002 M
Python executable: /usr/bin/python3
Config file: N/A
Inference address: http://127.0.0.1:8080
Management address: http://127.0.0.1:8081
Metrics address: http://127.0.0.1:8082
Model Store: /root/files/model_store
Initial Models: denoise_transformer=denoise_transformer.mar
Log dir: /root/files/logs
Metrics dir: /root/files/logs
Netty threads: 0
Netty client threads: 0
Default workers per model: 1
Blacklist Regex: N/A
Maximum Response Size: 6553500
Maximum Request Size: 6553500
Limit Maximum Image Pixels: true
Prefer direct buffer: false
Allowed Urls: [file://.*|http(s)?://.*]
Custom python dependency for model allowed: false
Metrics report format: prometheus
Enable metrics API: true
Workflow Store: /root/files/model_store
Model config: N/A
2022-08-24T14:06:06,805 [INFO ] main org.pytorch.serve.servingsdk.impl.PluginsManager -  Loading snapshot serializer plugin...
2022-08-24T14:06:06,817 [INFO ] main org.pytorch.serve.ModelServer - Loading initial models: denoise_transformer.mar
2022-08-24T14:06:07,006 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Adding new version 1.0 for model denoise_transformer
2022-08-24T14:06:07,007 [DEBUG] main org.pytorch.serve.wlm.ModelVersionedRefs - Setting default version to 1.0 for model denoise_transformer
2022-08-24T14:06:07,007 [INFO ] main org.pytorch.serve.wlm.ModelManager - Model denoise_transformer loaded.
2022-08-24T14:06:07,007 [DEBUG] main org.pytorch.serve.wlm.ModelManager - updateModel: denoise_transformer, count: 1
2022-08-24T14:06:07,015 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerLifeCycle - Worker cmdline: [/usr/bin/python3, /usr/local/lib/python3.8/dist-packages/ts/model_service_worker.py, --sock-type, unix, --sock-name, /tmp/.ts.sock.9000]
2022-08-24T14:06:07,016 [INFO ] main org.pytorch.serve.ModelServer - Initialize Inference server with: EpollServerSocketChannel.
2022-08-24T14:06:07,059 [INFO ] main org.pytorch.serve.ModelServer - Inference API bind to: http://127.0.0.1:8080
2022-08-24T14:06:07,059 [INFO ] main org.pytorch.serve.ModelServer - Initialize Management server with: EpollServerSocketChannel.
2022-08-24T14:06:07,060 [INFO ] main org.pytorch.serve.ModelServer - Management API bind to: http://127.0.0.1:8081
2022-08-24T14:06:07,060 [INFO ] main org.pytorch.serve.ModelServer - Initialize Metrics server with: EpollServerSocketChannel.
2022-08-24T14:06:07,062 [INFO ] main org.pytorch.serve.ModelServer - Metrics API bind to: http://127.0.0.1:8082
Model server started.
2022-08-24T14:06:07,258 [WARN ] pool-3-thread-1 org.pytorch.serve.metrics.MetricCollector - worker pid is not available yet.
2022-08-24T14:06:07,363 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Listening on port: /tmp/.ts.sock.9000
2022-08-24T14:06:07,364 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - [PID]6258
2022-08-24T14:06:07,364 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Torch worker started.
2022-08-24T14:06:07,365 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Python runtime: 3.8.10
2022-08-24T14:06:07,365 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change null -> WORKER_STARTED
2022-08-24T14:06:07,368 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Connecting to: /tmp/.ts.sock.9000
2022-08-24T14:06:07,374 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Connection accepted: /tmp/.ts.sock.9000.
2022-08-24T14:06:07,376 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Flushing req. to backend at: 1661317567376
2022-08-24T14:06:07,398 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - model_name: denoise_transformer, batchSize: 1
2022-08-24T14:06:07,596 [INFO ] pool-3-thread-1 TS_METRICS - CPUUtilization.Percent:0.0|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,596 [INFO ] pool-3-thread-1 TS_METRICS - DiskAvailable.Gigabytes:220.49971389770508|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,597 [INFO ] pool-3-thread-1 TS_METRICS - DiskUsage.Gigabytes:17.66714859008789|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,597 [INFO ] pool-3-thread-1 TS_METRICS - DiskUtilization.Percent:7.4|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,597 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUtilization.Percent:17.9931640625|#Level:Host,device_id:0|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,597 [INFO ] pool-3-thread-1 TS_METRICS - GPUMemoryUsed.Megabytes:1474|#Level:Host,device_id:0|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,598 [INFO ] pool-3-thread-1 TS_METRICS - GPUUtilization.Percent:8|#Level:Host,device_id:0|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,598 [INFO ] pool-3-thread-1 TS_METRICS - MemoryAvailable.Megabytes:14307.53515625|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,598 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUsed.Megabytes:1372.1640625|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:07,598 [INFO ] pool-3-thread-1 TS_METRICS - MemoryUtilization.Percent:10.6|#Level:Host|#hostname:5c780ba74916,timestamp:1661317567
2022-08-24T14:06:08,306 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - encoder self-attention layer type = self-attention
2022-08-24T14:06:08,328 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Eps is deprecated in si_snr loss, set clamp_db instead.
2022-08-24T14:06:08,373 [INFO ] W-9000-denoise_transformer_1.0-stdout MODEL_LOG - Perform direct speech enhancement on the input
2022-08-24T14:06:08,390 [INFO ] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - Backend response time: 992
2022-08-24T14:06:08,391 [DEBUG] W-9000-denoise_transformer_1.0 org.pytorch.serve.wlm.WorkerThread - W-9000-denoise_transformer_1.0 State change WORKER_STARTED -> WORKER_MODEL_LOADED
2022-08-24T14:06:08,391 [INFO ] W-9000-denoise_transformer_1.0 TS_METRICS - W-9000-denoise_transformer_1.0.ms:1380|#Level:Host|#hostname:5c780ba74916,timestamp:1661317568
2022-08-24T14:06:08,391 [INFO ] W-9000-denoise_transformer_1.0 TS_METRICS - WorkerThreadTime.ms:23|#Level:Host|#hostname:5c780ba74916,timestamp:1661317568

Is there somewhere wrong? Best regards.

Shin-ichi-Takayama commented 2 years ago

This issue is closed as it appears to be a curl issue, not torchserve.