You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by GitBox <gi...@apache.org> on 2021/01/14 10:04:55 UTC

[GitHub] [trafficserver] ema opened a new issue #7423: Significant mmap overhead in Lua plugin

ema opened a new issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423


   While investigating suspiciously high system CPU usage on a few servers running ATS, we observed that the traffic_server process was causing more than 50 thousand **mmap** calls per second, all of which with length 65536. 
   
   ```
   # pid 31316 is traffic_server
   $ sudo bpftrace -e 'kprobe:do_mmap /pid == 31316/ { @[arg2]=count(); } interval:s:1 { exit(); }'
   Attaching 2 probes...
   @[65536]: 64988
   ```
   By looking at LuaJIT's source code we found that the function **mcode_alloc_at** is responsible for calling mmap, so we  obtained a few backtraces for that function with the following SystemTap script:
   
   ```
   probe process("/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0").function("mcode_alloc_at") {
     print_ubacktrace()
     exit()
   }
   ```
   The script must be executed as follows to properly include all symbols:
   
   ```
   $ sudo stap -v -d /usr/bin/traffic_server -d /usr/lib/trafficserver/modules/tslua.so mcode_alloc_at.stp
   ```
   Most backtraces looked either like this:
   ```
    0x7fb44df01338 : mcode_allocarea+0xb8/0x160 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df19d54 : lj_asm_trace+0x25b4/0x3460 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df381d1 : trace_state+0x201/0x1340 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def2146 : lj_vm_cpcall+0x4a/0x5e [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def864b : lj_trace_ins+0x5b/0x70 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df410dc : lj_dispatch_call+0x21c/0x250 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def37ba : lj_vm_hotcall+0x1e/0x43 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df3f22c : lua_pcall+0x5c/0x80 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb52800d9a3 : globalHookHandler+0x313/0x450 [/usr/lib/trafficserver/modules/tslua.so]
   ```
   Or like this:
   
   ```
    0x7fb44df01338 : mcode_allocarea+0xb8/0x160 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df19d54 : lj_asm_trace+0x25b4/0x3460 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df381d1 : trace_state+0x201/0x1340 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def2146 : lj_vm_cpcall+0x4a/0x5e [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def864b : lj_trace_ins+0x5b/0x70 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df34e17 : lj_dispatch_ins+0x177/0x1e0 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def3741 : lj_vm_inshook+0x2d/0x44 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44df48ec1 : lj_cf_string_gsub+0x2e1/0x440 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb44def1dd7 : lj_BC_FUNCC+0x34/0x59 [/usr/lib/x86_64-linux-gnu/libluajit-5.1.so.2.1.0]
    0x7fb52801a0fe : ts_lua_http_cont_handler+0x15e/0x410 [/usr/lib/trafficserver/modules/tslua.so]
   ```
   
   I think the former traces are from tslua used as a global plugin, the latter for remap rules.
   
   Almost all our servers were affected by this, with the exception of a handful were traffic_server almost never called **mmap**. We do not have any valid theory explaining the difference, given that the servers run the same software stack and configuration. 
   However, the discrepancy allowed us to observe that on systems **not** calling mmap, the various Lua JIT trace calls (eg: **lj_trace_ins**) were also not called. We hence tried to disable the JIT compiler and only rely on the interpreter by adding **jit.off(true, true)** to all our Lua scripts. The result was that indeed mmap stopped being called, system CPU usage went down significantly, and the performance of ATS increased visibly. 
   
   ![ats-sys-cpu](https://user-images.githubusercontent.com/281102/104574876-d4a9b500-5656-11eb-9980-4f93200de2e2.png)
   
   We think that what might be happening is that the Lua JIT compiler keeps on identifying hot code and compiling it, instead of retaining and reusing the built code, or something along those lines. It would be great to:
   
   - better understand why the compiler is kicking in so often
   - have a configuration setting to turn off the compiler, similarly to what luajit's **-joff** does: https://luajit.org/running.html
   
   In **plugin.config** we have:
   
   ```
   tslua.so /etc/trafficserver/lua/default.lua --enable-reload
   ```
   
   **remap.config**: https://phabricator.wikimedia.org/P13769
   
   All lua scripts [here](https://gerrit.wikimedia.org/r/plugins/gitiles/operations/puppet/+/ab6958815d4d346ecfcca28724cd6d91a33d9eaf/modules/profile/files/trafficserver/).
   
   Our bug tracking system has [further details on the investigation](https://phabricator.wikimedia.org/T265625).
   
   
   
    


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] shukitchan commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
shukitchan commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-760347639


   Thanks for the thorough description. It is a very interesting problem. Let me try to dig deeper and see. 


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] ema commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
ema commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-809354214


   Hey Kit, sorry for getting back to you so late!
   
   > 1. Perhaps there are some failures to obtaining the memory needed for the operation and thus the luajit will keep doing it again and again? Did you guys see any messages in traffic.out/diags.log ?
   
   Nope, we're getting no relevant errors.
   
   > 3. if you are already on beta3 ,  I also wonder if this will help - [LuaJIT/LuaJIT@bd00094](https://github.com/LuaJIT/LuaJIT/commit/bd00094c3b50e193fb32aad79b7ea8ea6b78ed25)
   
   I gave it a shot, see https://phabricator.wikimedia.org/P15083. After installing the updated LuaJIT packages I got rid of our `jit.off()` workaround from all Lua scripts and here's the result:
   ![image](https://user-images.githubusercontent.com/281102/112839321-57f77600-909e-11eb-8118-605cb161f8cd.png)
   
   So no, unfortunately even with [LuaJIT/LuaJIT@bd00094](https://github.com/LuaJIT/LuaJIT/commit/bd00094c3b50e193fb32aad79b7ea8ea6b78ed25)  ATS is performing ~35K mmap calls per second:
   ```
   root@cp4027:/etc/trafficserver/lua# bpftrace -e 'uprobe:/lib/x86_64-linux-gnu/libc.so.6:mmap /pid==23625/ { @[pid]=count(); } interval:s:1 { exit(); }'
   Attaching 2 probes...
   @[23625]: 35203
   ```
   
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] shukitchan commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
shukitchan commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-760562775


   Some information i find about luajit / mmap - https://www.freelists.org/post/luajit/LuaJIT-and-mmap-scalability,10 
   Some of my thoughts: 
   
   1) Perhaps there are some failures to obtaining the memory needed for the operation and thus the luajit will keep doing it again and again? Did you guys see any messages in traffic.out/diags.log ?
   
   2) You guys seem to be at least using luajit 2.1.0 ? i think 2.1.0 beta3 has some of the mcode_alloc improvements. Are you guys already using beta3 ?
   
   3) if you are already on beta3 ,  I also wonder if this will help - https://github.com/LuaJIT/LuaJIT/commit/bd00094c3b50e193fb32aad79b7ea8ea6b78ed25
   


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] jvgutierrez commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
jvgutierrez commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-760960463


   We're using the 2.1.0 beta3 version packaged by debian: `2.1.0~beta3+dfsg-5.1`


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] shukitchan commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
shukitchan commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-1009672360


   Yes. I will submit a PR. 


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficserver.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] shukitchan commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
shukitchan commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-812901667


   Ok. Thanks for the test. 
   I think for now I will just add a configuration parameter to disable jit so it does not have to be inside the script. 


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] bryancall commented on issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
bryancall commented on issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423#issuecomment-1009490913


   @shukitchan Are you taking a look at this?


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficserver.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [trafficserver] shukitchan closed issue #7423: Significant mmap overhead in Lua plugin

Posted by GitBox <gi...@apache.org>.
shukitchan closed issue #7423:
URL: https://github.com/apache/trafficserver/issues/7423


   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: issues-unsubscribe@trafficserver.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org