4 ms·

Does anyone else experience Varnish using a surprising amount of CPU? I tried after seeing this benchmark [0] and thinking "that must be wrong". I got the same

Does anyone else experience Varnish using a surprising amount of CPU? I tried after seeing this benchmark [0] and thinking "that must be wrong". I got the same results. Benchmarking on a 1GB, 1vCPU cloud server (to get an idea of what it would handle), with minimal VCL and one 15kb file in Varnish's in-memory cache it used over half the CPU (with hitch, unsurprisingly, using the other half for SSL termination). [0] https://twitter.com/BlackIkeEagle/status/1274977171400847361 https://twitter.com/BlackIkeEagle/status/1274977171400847361

fwsgonzo 6y ago
I'm just doing regular benchmarking here: https://1drv.ms/u/s!Aqr3qxYHlh9rgfVUKdE7Y9oYo5pOVQ?e=2GWdJU https://1drv.ms/u/s!Aqr3qxYHlh9rgfVUKdE7Y9oYo5pOVQ?e=2GWdJU But as you can see, it's not much CPU at 450'000 reqs/sec, and the response time is just fine, at 1ms average. The benchmark is at first hitting one of my emulated VMs, but it gets cached, which is a fast-path. I think benchmarking anything other than a cache hit, is not doing a cache justice. Generally, the cache hit ratio is very high when properly configured. I did not look into what the Litespeed benchmark was doing though, so I can't comment on that. What exactly is your VCL here?
- pbowyer 6y ago
  This is my VCL: https://gist.github.com/pbowyer/8822ab1d61fc209056f0f6bc694319f7 https://gist.github.com/pbowyer/8822ab1d61fc209056f0f6bc6943... And how Varnish is initialised ExecStart=/usr/sbin/varnishd -a :80 -a 127.0.0.1:6081,PROXY -f /etc/varnish/default.vcl -s malloc,64m -p feature=+http2 I've verified everything is a cache hit, and the ratio is 1.000 by the end of testing. Screenshots and more in this thread: https://twitter.com/peterbowyer/status/1292765478100795393 https://twitter.com/peterbowyer/status/1292765478100795393
  - fwsgonzo 6y ago
    Hey, just woke up. I don't see anything wrong here, so I think I will second the other commenter. I wonder if the VMs are over-subscribed? Is there any way to tell or would that be a business secret? I also think we should consider how CPU usage is calculated as well. I don't know how it's done inside VMs, but I can easily imagine that there are several cases where it would include time where the CPU is just waiting for things like access to memory or even waiting on I/O as long as that happens through a shared memory ring buffer, via spinning or something to that effect. So, if that is how it works, then over-subscription of VMs could cause them to show higher CPU usage. But, I don't know, and I hope someone more familiar with the subject will join the discussion.
    - pbowyer 6y ago
      There's no way to tell if over-subscribed AFAIK. The VM is with UpCloud as I had credits there. I haven't used strace before but I ran it and perf top and have put images at https://twitter.com/peterbowyer/status/1294181276061241344 https://twitter.com/peterbowyer/status/1294181276061241344. The __memset_avx2_erms is present even with 5 concurrent requests (but at 11% overhead then) and the core dump still happens. Very odd.
- flas9sd 6y ago
  If I'd like to profile VCL subroutines, is valgrind the obvious tool to reach for?
67868018 6y ago
There is something else wrong with your server. Very wrong. You need to do some process tracing and find out what syacalls are so expensive that you're seeing this kind of CPU usage
- pbowyer 6y ago
  Thanks - will strace attached to the master Varnish process do the job?
  - pbowyer 6y ago
    I did my best and I've put images & info @ https://twitter.com/peterbowyer/status/1294181276061241344 https://twitter.com/peterbowyer/status/1294181276061241344.

fwsgonzo 6y ago

I'm just doing regular benchmarking here: https://1drv.ms/u/s!Aqr3qxYHlh9rgfVUKdE7Y9oYo5pOVQ?e=2GWdJU https://1drv.ms/u/s!Aqr3qxYHlh9rgfVUKdE7Y9oYo5pOVQ?e=2GWdJU But as you can see, it's not much CPU at 450'000 reqs/sec, and the response time is just fine, at 1ms average. The benchmark is at first hitting one of my emulated VMs, but it gets cached, which is a fast-path. I think benchmarking anything other than a cache hit, is not doing a cache justice. Generally, the cache hit ratio is very high when properly configured. I did not look into what the Litespeed benchmark was doing though, so I can't comment on that. What exactly is your VCL here?

pbowyer 6y ago
This is my VCL: https://gist.github.com/pbowyer/8822ab1d61fc209056f0f6bc694319f7 https://gist.github.com/pbowyer/8822ab1d61fc209056f0f6bc6943... And how Varnish is initialised ExecStart=/usr/sbin/varnishd -a :80 -a 127.0.0.1:6081,PROXY -f /etc/varnish/default.vcl -s malloc,64m -p feature=+http2 I've verified everything is a cache hit, and the ratio is 1.000 by the end of testing. Screenshots and more in this thread: https://twitter.com/peterbowyer/status/1292765478100795393 https://twitter.com/peterbowyer/status/1292765478100795393
- fwsgonzo 6y ago
  Hey, just woke up. I don't see anything wrong here, so I think I will second the other commenter. I wonder if the VMs are over-subscribed? Is there any way to tell or would that be a business secret? I also think we should consider how CPU usage is calculated as well. I don't know how it's done inside VMs, but I can easily imagine that there are several cases where it would include time where the CPU is just waiting for things like access to memory or even waiting on I/O as long as that happens through a shared memory ring buffer, via spinning or something to that effect. So, if that is how it works, then over-subscription of VMs could cause them to show higher CPU usage. But, I don't know, and I hope someone more familiar with the subject will join the discussion.
  - pbowyer 6y ago
    There's no way to tell if over-subscribed AFAIK. The VM is with UpCloud as I had credits there. I haven't used strace before but I ran it and perf top and have put images at https://twitter.com/peterbowyer/status/1294181276061241344 https://twitter.com/peterbowyer/status/1294181276061241344. The __memset_avx2_erms is present even with 5 concurrent requests (but at 11% overhead then) and the core dump still happens. Very odd.
flas9sd 6y ago
If I'd like to profile VCL subroutines, is valgrind the obvious tool to reach for?

67868018 6y ago

There is something else wrong with your server. Very wrong. You need to do some process tracing and find out what syacalls are so expensive that you're seeing this kind of CPU usage

pbowyer 6y ago
Thanks - will strace attached to the master Varnish process do the job?
- pbowyer 6y ago
  I did my best and I've put images & info @ https://twitter.com/peterbowyer/status/1294181276061241344 https://twitter.com/peterbowyer/status/1294181276061241344.