New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Profile new changes #8

Closed
p0pr0ck5 opened this Issue Jan 19, 2015 · 9 comments

Comments

Projects
None yet
1 participant
@p0pr0ck5
Copy link
Owner

p0pr0ck5 commented Jan 19, 2015

See how more more (if any) new delay has been introduced by changes like ignore_ruleset (which is inefficient and now runs with every request)

@p0pr0ck5 p0pr0ck5 self-assigned this Jan 19, 2015

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Jan 19, 2015

Actually, this isn't bad at all. new() and set_option only take up around 2.5%, avg runtime is just over 500 microseconds. flamegraph at https://cb-objs.objects.cdn.dream.io/fw-profile-20150119.svg

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Jan 21, 2015

c26e36e was really dumb- now we have to create the lookup table each time, frigging stupid. https://objects.dreamhost.com/cb-objs/fw-profile-20150121.svg

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Jan 21, 2015

Did a test removing all _log() directives (which are expensive because of eager string evaluation), avg runtime dropped to around 450 microseconds. cleaner flame graph too: https://objects.dreamhost.com/cb-objs/fw-profile-20150121-2.svg

Another test with a few cookies containing somewhat large cookie values (about 500 bytes, session cookies) and a query string ?foo=bar: https://objects.dreamhost.com/cb-objs/fw-profile-20150121-3.svg. runtime jumped to 2.2ms there. almost 90% is from regexes, with about 70% used by ngx.re.find, the rest from the overhead of recursing. seems like a good tradeoff there.

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Jan 28, 2015

Not caching transforms lead to severe degredation (+4ms runtimes); results from adding html_decode transforms to the 42000 rulesets (which follows with CRS behavior): https://objects.dreamhost.com:443/cb-objs/fw-profile-20150127-t-nocache.svg

Caching transforms as part of ctx.collections (902d09e) is a massive improvement: https://objects.dreamhost.com/cb-objs/fw-profile-20150128-t-cache-heavy.svg

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Feb 9, 2015

Adding the new 10000 ruleset brings runtime down to ~120 microseconds for static resources (almost half of the time was spent on set_option). Had trouble generating a valid flame graph with a few rules testing hitcount, but exec time showed an average of 750 microseconds, so we should avoid pushing rulesets with too many uses of variables, but it's not going to be an absolute killer, especially in conjunction with static whitelisting.

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Mar 1, 2015

Definitely an upward-growing trend as we add more features, averaged around 850 microseconds. but more development means more (expensive) debug logging; building the strings when generating logs is a major slowdown. Hit 277/508/1388 after getting rid of debug logs:

sed -i '/^\s*_log(/d' fw.lua

https://objects.dreamhost.com:443/cb-objs/fw-profile-20150301-no_log.svg

Will add a note in the docs under the performance header about this, and will probably remove debug logging at some point all together.

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Mar 2, 2015

Pushed 0750aab to test disabling PCRE JIT compilation and pattern caching, as part of troubleshooting in issue #24, and... ow:

https://objects.dreamhost.com/cb-objs/fw-profile-20150302-disable_pcre_optimization.svg

With exec times of 2077/2208/27246. Gonna leave a big note about this, but still going to give users enough rope to hang themselves.

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Jan 15, 2016

269/347/13356 after 03d2509 and sed'ing out logger.log calls.

@p0pr0ck5

This comment has been minimized.

Copy link
Owner

p0pr0ck5 commented Feb 2, 2016

Going to close this out as there's no really much to actually do here. I'm still perf testing on a regular basis, and recommending support for resty.core will be a bigger bump (once openresty/lua-resty-core#22 is ironed out).

@p0pr0ck5 p0pr0ck5 closed this Feb 2, 2016

@p0pr0ck5 p0pr0ck5 referenced this issue Aug 18, 2016

Closed

[Performance] #196

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment