Memory is increasing

[YingChenlu]

I use torchserve 0.0.1 to run cpu model. The memory used by each worker is increasing and finally the server crashes. How to solve it?

hs_err_pid16037.log

[mycpuorg]

Hi @YingChenlu
Thanks for sharing the profiler log.

I have a few questions:

• It looks like you have a 2-core machine with 7GB RAM, how large is the model?
• What's the avg increase in memory size per request?
• Is it possible to share the model and handlers? If not, is there any public model/handler that's similar to yours?
• Do you have multiple models registered or a single model?
• Are you using default config options or have you modified any?
• The server appears to be running at least 10 processes on your 2-core machine (can you please confirm this?)
• Can you share the logs from Torchserve?
• How big is the input?
• How many requests is the server receiving when you observe this memory increase?
• Are you receiving error codes for requests before the crash?

In any case, there are a lot of config options you could look into here: https://github.com/pytorch/serve/blob/master/docs/configuration.md
I'd start with the following:

• number_of_netty_threads: number frontend netty thread. Default: number of logical processors available to the JVM.
• netty_client_threads: number of backend netty thread. Default: number of logical processors available to the JVM.
• default_workers_per_model: number of workers to create for each model that loaded at startup time. Default: available GPUs in system or number of logical processors available to the JVM.
• job_queue_size: number inference jobs that frontend will queue before backend can serve. Default: 100.

[YingChenlu]

Hi @mycpuorg
Thank you for your reply. I re-run my test with 3000 requests. This time the server doesn't crash. But the memory is still increasing and as I monitor the memory usage shown by top command, when the memory is ran out, one of the 2 backend workers dies and the server re-starts another worker.

• It looks like you have a 2-core machine with 7GB RAM, how large is the model?
  The mar file is 496M and my model has 200M parameters.

• What's the avg increase in memory size per request?
  For my last run, the initial memory used by each progress is 13.5%. After 1671 requests, the server crash due to memory problem. So the avg increase per request is about 3.5M.
  For this run with 3000 requests, the 1st worker death happends after 1248 requests.

• Is it possible to share the model and handlers? If not, is there any public model/handler that's similar to yours?
  Sorry I can't share. My model is for automatic speech recognition. As for as I know, no public model/handler is similar to mine. When recognizing a utterance, the beam size is 5, which is actually the batch size.

• Do you have multiple models registered or a single model?
  Just a single model.

• Are you using default config options or have you modified any?
  Default.

• The server appears to be running at least 10 processes on your 2-core machine (can you please confirm this?)
  There are 2 processes shown by top command.

• Can you share the logs from Torchserve?
  See attachments for logs of this run with 3000 requests. (model_log.log is empty)

• How big is the input?
  Then average size of a input is a 500x80 float32 array, which is about 160KB.

• How many requests is the server receiving when you observe this memory increase?
  It seems the memory increases from the 1st request.

• Are you receiving error codes for requests before the crash?
  For my last run, there is one line:
  commit_memory(0x00007fa2b71f2000, 16384, 0) failed; error='Not enough space'.

Besides, as long as torchserve is running, the memory wouldn't be released even test finishes and no requests are posted.

ts_metrics.log
ts_log.log
model_metrics.log
access_log.log

[codinnvrends]

Tried with docker having 2GB and 2 cores + vgg11 model (size - 471MB) for 3000 requests.
Unable to repro exact issue however observing an overall increase in memory footprint. Next, will check again with the different configuration on ubuntu ec2 instead of docker.

In the following top output, memory usage has increased from initial ~1.2GB [when workers started] to test ended ~1.6GB.

** Before loading model **

top - 14:30:31 up  3:47,  0 users,  load average: 0.02, 0.26, 1.18
Tasks:   5 total,   1 running,   4 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.5 us,  1.5 sy,  0.0 ni, 97.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  2037620 total,  1595744 free,   **303476 used**,   138400 buff/cache
KiB Swap:  1048572 total,   807468 free,   241104 used.  1591848 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                  
    7 model-s+  20   0 3235616 169412  19008 S   1.7  8.3   2:12.48 java                                                                     
    1 model-s+  20   0   18376      0      0 S   0.0  0.0   0:00.09 dockerd-entrypo                                                          
    8 model-s+  20   0    4568     12      0 S   0.0  0.0   0:00.37 tail                                                                     
   54 model-s+  20   0   18508      4      4 S   0.0  0.0   0:00.27 bash                                                                     
  262 model-s+  20   0   36616   1244    988 R   0.0  0.1   0:01.37 top

** After loading model **

top - 14:31:59 up  3:48,  0 users,  load average: 0.55, 0.34, 1.12
Tasks:   7 total,   1 running,   6 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.3 us,  1.7 sy,  0.0 ni, 95.9 id,  1.5 wa,  0.0 hi,  0.5 si,  0.0 st
KiB Mem :  2037620 total,   790176 free,  **1166608 used**,    80836 buff/cache
KiB Swap:  1048572 total,   513020 free,   535552 used.   755156 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                  
    7 model-s+  20   0 3235616  45156  12120 S   1.0  2.2   2:28.22 java                                                                     
  262 model-s+  20   0   36616   1536   1284 R   0.3  0.1   0:01.58 top                                                                      
    1 model-s+  20   0   18376      0      0 S   0.0  0.0   0:00.09 dockerd-entrypo                                                          
    8 model-s+  20   0    4568     12      0 S   0.0  0.0   0:00.38 tail                                                                     
   54 model-s+  20   0   18508      4      4 S   0.0  0.0   0:00.27 bash                                                                     
  362 model-s+  20   0 2045064 534132   9464 S   0.0 26.2   0:04.51 python3                                                                  
  364 model-s+  20   0 2045048 533428   8704 S   0.0 26.2   0:06.16 python3

** Post 3k request execution**

top - 18:17:13 up  5:40,  0 users,  load average: 0.00, 0.02, 0.03
Tasks:   7 total,   1 running,   6 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.7 sy,  0.0 ni, 99.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  2037620 total,   325480 free,  `**1566980 used,**`   145160 buff/cache
KiB Swap:  1048572 total,   648700 free,   399872 used.   328600 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                  
    7 model-s+  20   0 3235616 168148  18100 S   1.0  8.3   4:01.13 java                                                                     
  262 model-s+  20   0   36616   1536   1284 R   0.3  0.1   0:05.84 top                                                                      
    1 model-s+  20   0   18376      0      0 S   0.0  0.0   0:00.09 dockerd-entrypo                                                          
    8 model-s+  20   0    4568     12      0 S   0.0  0.0   0:00.97 tail                                                                     
   54 model-s+  20   0   18508      4      4 S   0.0  0.0   0:00.27 bash                                                                     
  362 model-s+  20   0 2219004 656744  22016 S   0.0 32.2  14:33.93 python3                                                                  
  364 model-s+  20   0 2231532 669208  22016 S   0.0 32.8  14:32.97 python3 

Tested with apache benchmark for 3000 requests - No failures

$ ab -c 100 -n 3000 -k -p kitten.jpg -T application/jpg http://localhost:8080/predictions/vgg11
This is ApacheBench, Version 2.3 <$Revision: 1826891 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 300 requests
Completed 600 requests
Completed 900 requests
Completed 1200 requests
Completed 1500 requests
Completed 1800 requests
Completed 2100 requests
Completed 2400 requests
Completed 2700 requests
Completed 3000 requests
Finished 3000 requests


Server Software:        
Server Hostname:        localhost
Server Port:            8080

Document Path:          /predictions/vgg11
Document Length:        222 bytes

Concurrency Level:      100
Time taken for tests:   922.193 seconds
Complete requests:      3000
Failed requests:        0
Keep-Alive requests:    3000
Total transferred:      1365000 bytes
Total body sent:        333444000
HTML transferred:       666000 bytes
Requests per second:    3.25 [#/sec] (mean)
Time per request:       30739.751 [ms] (mean)
Time per request:       307.398 [ms] (mean, across all concurrent requests)
Transfer rate:          1.45 [Kbytes/sec] received
                        353.10 kb/s sent
                        354.55 kb/s total

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   1.9      0      14
Processing:  1665 30201 3010.0  30363   35231
Waiting:     1651 30201 3010.1  30363   35231
Total:       1665 30201 3008.6  30363   35238

Percentage of the requests served within a certain time (ms)
  50%  30363
  66%  30877
  75%  31305
  80%  31559
  90%  32162
  95%  32801
  98%  33365
  99%  33964
 100%  35238 (longest request)

[codinnvrends]

@YingChenlu Can you please share the top command output for the following state -

1. No model loaded
2. Model loaded [with worker]
3. Post 4 inference requests
4. Post 3k requests [copy top output after a pause of 5 mins]

We need these inputs to understand the model footprint. We are observing an increase in memory however it is not following the pattern you have described. There are few things to be noted -

1. For the first inference request, the corresponding worker process [python] memory footprint increases by ~200MB [vgg11 model]. However, this remains constant for later requests
2. Main process memory is not getting released however it is not increasing with the pace described by you.
3. On docker with 2 core/2gb RAM, unable to reproduce this issue i.e. worker restart.

[mycpuorg]

Thanks @dhaniram-kshirsagar this is very useful info. The workers are spawned and they load the corresponding model into memory so the initial increase is justified. But the memory must remain constant (within a channel) after this.

@dhaniram-kshirsagar It is not clear if your experiment actually recreates the issue reported here. Can you confirm that your test is actually reproducing this issue?

[mycpuorg]

@YingChenlu the server should release the memory once the model is unregistered. Nonetheless, thanks for bringing this issue up as it's very important. I have created a related request to bring in some optimizations we had discussed from a while back. Please refer and comment: #419

[YingChenlu]

For me, memory increase happens with different requests. With the same request, the memory is almost constant. I'll post more logs later.