apache / incubator-pagespeed-ngx

Automatic PageSpeed optimization module for Nginx
http://ngxpagespeed.com/
Apache License 2.0
4.37k stars 365 forks source link

Heavy memory consumption after processing big pages with huge count of images #1212

Open n0guest opened 8 years ago

n0guest commented 8 years ago

Hi.

We have very strange issue with ngx_pagespeed. Our web developers by mistake created very huge page (~15Mb). And this page contains ~35k images tags. At start child proccess of nginx consumes ~40Mb, but after processing request to this pages it will be ~2-2.5Gb. And memory consumption of this process never goes down. Only after re-creating child processes via nginx -s reload. And one more thing - when ngx_pagespeed is processing this page it also overload backend with 400-550 req/sec. All those requests to images from html.

I understand. that this is a really stupid situation and not even close to 'typical" environment. But i'm trying to find a way for fixing it by changing parameters of ngx_pagespeed. But for now all my attempts failed.

Here is information about nginx and ngx_pagespeed versions:

# nginx -V 2>&1 | sed 's/--/\n--/g'
nginx version: nginx/1.10.1
built with OpenSSL 1.0.1f 6 Jan 2014
TLS SNI support enabled
configure arguments:
--with-cc-opt='-g -O2 -fPIE -fstack-protector
--param=ssp-buffer-size=4 -Wformat -Werror=format-security -D_FORTIFY_SOURCE=2'
--with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now'
--prefix=/usr/share/nginx
--conf-path=/etc/nginx/nginx.conf
--http-log-path=/var/log/nginx/access.log
--error-log-path=/var/log/nginx/error.log
--lock-path=/var/lock/nginx.lock
--pid-path=/run/nginx.pid
--http-client-body-temp-path=/var/lib/nginx/body
--http-fastcgi-temp-path=/var/lib/nginx/fastcgi
--http-proxy-temp-path=/var/lib/nginx/proxy
--http-scgi-temp-path=/var/lib/nginx/scgi
--http-uwsgi-temp-path=/var/lib/nginx/uwsgi
--with-debug
--with-pcre-jit
--with-ipv6
--with-http_ssl_module
--with-http_stub_status_module
--with-http_realip_module
--with-http_auth_request_module
--with-http_addition_module
--with-http_dav_module
--with-http_flv_module
--with-http_geoip_module
--with-http_gunzip_module
--with-http_gzip_static_module
--with-http_image_filter_module
--with-http_mp4_module
--with-http_perl_module
--with-http_random_index_module
--with-http_secure_link_module
--with-http_v2_module
--with-http_sub_module
--with-http_xslt_module
--with-mail
--with-mail_ssl_module
--with-stream
--with-stream_ssl_module
--with-threads
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/headers-more-nginx-module
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-auth-pam
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/ngx_pagespeed
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-cache-purge
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-dav-ext-module
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-development-kit
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-echo
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/ngx-fancyindex
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-http-push
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-push-stream-module
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-lua
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-upload-progress
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/nginx-upstream-fair
--add-module=/usr/local/src/nginx-1.10.1/debian/modules/ngx_http_substitutions_filter_module

And current configutation:

Version: 14: on

Filters
ah  Add Head
ij  Canonicalize Javascript library URLs
cw  Collapse Whitespace
cc  Combine Css
jc  Combine Javascript
gp  Convert Gif to Png
jp  Convert Jpeg to Progressive
jw  Convert Jpeg To Webp
mc  Convert Meta Tags
pj  Convert Png to Jpeg
ws  When converting images to WebP, prefer lossless conversions
ec  Cache Extend Css
ei  Cache Extend Images
es  Cache Extend Scripts
fc  Fallback Rewrite Css
if  Flatten CSS Imports
hw  Flushes html
ci  Inline Css
gf  Inline Google Font CSS
ii  Inline Images
il  Inline @import to Link
ji  Inline Javascript
io  In-place optimize for browser
idp Insert DNS Prefetch
js  Jpeg Subsampling
cj  Move Css Above Scripts
rj  Recompress Jpeg
rp  Recompress Png
rw  Recompress Webp
ri  Resize Images
cf  Rewrite Css
jm  Rewrite External Javascript
jj  Rewrite Inline Javascript
cu  Rewrite Style Attributes With Url
is  Sprite Images
cp  Strip Image Color Profiles
md  Strip Image Meta Data

Options
  AdminPath (nap)                              /pagespeed_admin
  AvoidRenamingIntrospectiveJavascript (aris)  True
  BeaconUrl (bu)                               /ngx_pagespeed_beacon
  ConsolePath (ncp)                            /pagespeed_console
  CriticalImagesBeaconEnabled (cibe)           False
  DefaultSharedMemoryCacheKB (dsmc)            50000
  EnableCachePurge (euci)                      True
  EnableRewriting (e)                          1
  FetchHttps (fhs)                             enable,allow_self_signed,allow_unknown_certificate_authority,allow_certificate_not_yet_valid
  FileCacheInodeLimit (afcl)                   500000
  FileCachePath (afcp)                         /var/tmp/nginx/ngx_pagespeed_cache
  GlobalAdminPath (ngap)                       /pagespeed_global_admin
  GlobalStatisticsPath (ngsp)                  /ngx_pagespeed_global_statistics
  InPlaceResourceOptimization (ipro)           True
  LogDir (ald)                                 /var/log/nginx/pagespeed
  LowercaseHtmlNames (lh)                      True
  LRUCacheByteLimit (alcb)                     16384
  LRUCacheKbPerProcess (alcp)                  8192
  MemcachedServers (ams)                       127.0.0.1:11212
  MessagesPath (nmp)                           /ngx_pagespeed_message
  RateLimitBackgroundFetches (rlbf)            True
  RespectVary (rv)                             True
  RewriteLevel (l)                             Core Filters
  Statistics (ase)                             True
  StatisticsLogging (asle)                     True
  StatisticsPath (nsp)                         /ngx_pagespeed_statistics
  XHeaderValue (xhv)                           X.Y.Z-who-cares

Domain Lawyer
  http://*.ourdomain.tld/ Auth
  http://ourdomain.tld/ Auth
  https://*.ourdomain.tld/ Auth
  https://ourdomain.tld/ Auth

Invalidation Timestamp: (none)
n0guest commented 8 years ago

And here is memory maps of same process - before and after processing such "heavy" page.

map-14759.txt map-14759-after.txt

I hope it can help someway.

n0guest commented 8 years ago

Looks like i've found what can cause such memory hunger. Here is how looks "hottest" place in perf report (from perf_event):

-  35.96%    nginx  nginx                [.] longest_match
   + longest_match
   + deflate_slow
   + pagespeed_ol_deflate
   + pagespeed_ol_png_write_filtered_row
   + pagespeed_ol_png_write_find_filter
   + pagespeed_ol_png_write_row
   + pagespeed_ol_png_write_image
   + pagespeed_ol_png_write_png
   + pagespeed::image_compression::PngOptimizer::WritePng(pagespeed::image_compression::ScopedPngStruct*, std::string*)
   + pagespeed::image_compression::PngOptimizer::CreateOptimizedPngWithParams(pagespeed::image_compression::ScopedPngStruct*, pagespeed::image_compression::PngCompressParams const&, std::string*)
   + pagespeed::image_compression::PngOptimizer::CreateBestOptimizedPngForParams(pagespeed::image_compression::PngCompressParams const*, unsigned long, std::string*)
   + pagespeed::image_compression::PngOptimizer::CreateOptimizedPng(pagespeed::image_compression::PngReaderInterface const&, std::string const&, std::string*, net_instaweb::MessageHandler*)
   + pagespeed::image_compression::PngOptimizer::OptimizePngBestCompression(pagespeed::image_compression::PngReaderInterface const&, std::string const&, std::string*, net_instaweb::MessageHandler*)
   + net_instaweb::ImageImpl::ComputeOutputContentsFromGifOrPng(std::string const&, pagespeed::image_compression::PngReaderInterface const*, bool, char const*, net_instaweb::ImageType, net_instaweb::Image::ConversionVariables::VariableType)
   + net_instaweb::ImageImpl::ComputeOutputContents()
   + net_instaweb::Image::output_size()
   - net_instaweb::ImageRewriteFilter::RewriteLoadedResourceImpl(net_instaweb::ImageRewriteFilter::Context*, net_instaweb::RefCountedPtr<net_instaweb::Resource> const&, net_instaweb::RefCountedPtr<net_instaweb::OutputResource> const&)
      - 100.00% net_instaweb::ImageRewriteFilter::Context::InvokeRewriteFunction::RunImpl(net_instaweb::scoped_ptr<net_instaweb::ExpensiveOperationContext>*)
           net_instaweb::CentralControllerCallback<net_instaweb::ExpensiveOperationContext>::RunAfterRequeue()
           net_instaweb::MemberFunction0<net_instaweb::CentralControllerCallback<net_instaweb::ExpensiveOperationContext> >::Run()
           net_instaweb::Function::CallRun()
           net_instaweb::QueuedWorkerPool::Run(net_instaweb::QueuedWorkerPool::Sequence*, net_instaweb::QueuedWorker*)
           net_instaweb::MemberFunction2<net_instaweb::QueuedWorkerPool, net_instaweb::QueuedWorkerPool::Sequence*, net_instaweb::QueuedWorker*>::Run()
           net_instaweb::Function::CallRun()
           net_instaweb::Worker::WorkThread::Run()
           net_instaweb::PthreadThreadImpl::InvokeRun(void*)

And same information as a flamegraph here https://p.osshelp.ru/pagespeed-flamegraph.svg. After disabling "rewrite_images" problem was gone. But, i guess, i've fully disabled image optimization. And it isn't a right solution for this issue.

jmarantz commented 8 years ago

Hi -- I'm not sure what you have MaxImageRewritesAtOnce set to, but I think this might be related to https://github.com/pagespeed/mod_pagespeed/issues/1305 which is fixed in trunk, but not yet released.

-Josh

On Thu, Jun 9, 2016 at 8:28 PM, Evgeniy K. notifications@github.com wrote:

Looks like i've found what can cause such memory hunger. Here is how looks "hottest" place in perf report (from perf_event):

  • 35.96% nginx nginx [.] longest_match
    • longest_match
    • deflate_slow
    • pagespeed_ol_deflate
    • pagespeed_ol_png_write_filtered_row
    • pagespeed_ol_png_write_find_filter
    • pagespeed_ol_png_write_row
    • pagespeed_ol_png_write_image
    • pagespeed_ol_png_write_png
    • pagespeed::image_compression::PngOptimizer::WritePng(pagespeed::imagecompression::ScopedPngStruct, std::string_)
    • pagespeed::image_compression::PngOptimizer::CreateOptimizedPngWithParams(pagespeed::imagecompression::ScopedPngStruct, pagespeed::imagecompression::PngCompressParams const&, std::string)
    • pagespeed::image_compression::PngOptimizer::CreateBestOptimizedPngForParams(pagespeed::imagecompression::PngCompressParams const, unsigned long, std::string_)
    • pagespeed::image_compression::PngOptimizer::CreateOptimizedPng(pagespeed::imagecompression::PngReaderInterface const&, std::string const&, std::string, netinstaweb::MessageHandler)
    • pagespeed::image_compression::PngOptimizer::OptimizePngBestCompression(pagespeed::imagecompression::PngReaderInterface const&, std::string const&, std::string, netinstaweb::MessageHandler)
    • net_instaweb::ImageImpl::ComputeOutputContentsFromGifOrPng(std::string const&, pagespeed::imagecompression::PngReaderInterface const, bool, char const_, net_instaweb::ImageType, net_instaweb::Image::ConversionVariables::VariableType)
    • net_instaweb::ImageImpl::ComputeOutputContents()
    • net_instaweb::Image::output_size()
    • net_instaweb::ImageRewriteFilter::RewriteLoadedResourceImpl(net_instaweb::ImageRewriteFilter::Context*, net_instaweb::RefCountedPtr const&, net_instaweb::RefCountedPtr const&)
    • 100.00% net_instaweb::ImageRewriteFilter::Context::InvokeRewriteFunction::RunImpl(net_instaweb::scoped_ptr_) net_instaweb::CentralControllerCallback::RunAfterRequeue() net_instaweb::MemberFunction0<net_instaweb::CentralControllerCallback >::Run() net_instaweb::Function::CallRun() net_instaweb::QueuedWorkerPool::Run(netinstaweb::QueuedWorkerPool::Sequence, netinstaweb::QueuedWorker) net_instaweb::MemberFunction2<net_instaweb::QueuedWorkerPool, netinstaweb::QueuedWorkerPool::Sequence, netinstaweb::QueuedWorker>::Run() net_instaweb::Function::CallRun() net_instaweb::Worker::WorkThread::Run() netinstaweb::PthreadThreadImpl::InvokeRun(void)

And same information as a flamegraph here https://p.osshelp.ru/pagespeed-flamegraph.svg. And after disabling "rewrite_images" problem was gone. But, i guess, i've fully disabled image optimization. And it isn't a right solution for this issue.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/pagespeed/ngx_pagespeed/issues/1212#issuecomment-225064868, or mute the thread https://github.com/notifications/unsubscribe/AB2kPXfgS2Oy95V0KvsY8qKMNAJaB-FJks5qKK-SgaJpZM4IygRC .

jmarantz commented 8 years ago

If you want to patch it, it looks like this is the fix: https://github.com/pagespeed/mod_pagespeed/pull/1312

-Josh

On Thu, Jun 9, 2016 at 10:45 PM, Joshua Marantz jmarantz@google.com wrote:

Hi -- I'm not sure what you have MaxImageRewritesAtOnce set to, but I think this might be related to https://github.com/pagespeed/mod_pagespeed/issues/1305 which is fixed in trunk, but not yet released.

-Josh

On Thu, Jun 9, 2016 at 8:28 PM, Evgeniy K. notifications@github.com wrote:

Looks like i've found what can cause such memory hunger. Here is how looks "hottest" place in perf report (from perf_event):

  • 35.96% nginx nginx [.] longest_match
    • longest_match
    • deflate_slow
    • pagespeed_ol_deflate
    • pagespeed_ol_png_write_filtered_row
    • pagespeed_ol_png_write_find_filter
    • pagespeed_ol_png_write_row
    • pagespeed_ol_png_write_image
    • pagespeed_ol_png_write_png
    • pagespeed::image_compression::PngOptimizer::WritePng(pagespeed::imagecompression::ScopedPngStruct, std::string_)
    • pagespeed::image_compression::PngOptimizer::CreateOptimizedPngWithParams(pagespeed::imagecompression::ScopedPngStruct, pagespeed::imagecompression::PngCompressParams const&, std::string)
    • pagespeed::image_compression::PngOptimizer::CreateBestOptimizedPngForParams(pagespeed::imagecompression::PngCompressParams const, unsigned long, std::string_)
    • pagespeed::image_compression::PngOptimizer::CreateOptimizedPng(pagespeed::imagecompression::PngReaderInterface const&, std::string const&, std::string, netinstaweb::MessageHandler)
    • pagespeed::image_compression::PngOptimizer::OptimizePngBestCompression(pagespeed::imagecompression::PngReaderInterface const&, std::string const&, std::string, netinstaweb::MessageHandler)
    • net_instaweb::ImageImpl::ComputeOutputContentsFromGifOrPng(std::string const&, pagespeed::imagecompression::PngReaderInterface const, bool, char const_, net_instaweb::ImageType, net_instaweb::Image::ConversionVariables::VariableType)
    • net_instaweb::ImageImpl::ComputeOutputContents()
    • net_instaweb::Image::output_size()
    • net_instaweb::ImageRewriteFilter::RewriteLoadedResourceImpl(net_instaweb::ImageRewriteFilter::Context*, net_instaweb::RefCountedPtr const&, net_instaweb::RefCountedPtr const&)
    • 100.00% net_instaweb::ImageRewriteFilter::Context::InvokeRewriteFunction::RunImpl(net_instaweb::scoped_ptr_) net_instaweb::CentralControllerCallback::RunAfterRequeue() net_instaweb::MemberFunction0<net_instaweb::CentralControllerCallback >::Run() net_instaweb::Function::CallRun() net_instaweb::QueuedWorkerPool::Run(netinstaweb::QueuedWorkerPool::Sequence, netinstaweb::QueuedWorker) net_instaweb::MemberFunction2<net_instaweb::QueuedWorkerPool, netinstaweb::QueuedWorkerPool::Sequence, netinstaweb::QueuedWorker>::Run() net_instaweb::Function::CallRun() net_instaweb::Worker::WorkThread::Run() netinstaweb::PthreadThreadImpl::InvokeRun(void)

And same information as a flamegraph here https://p.osshelp.ru/pagespeed-flamegraph.svg. And after disabling "rewrite_images" problem was gone. But, i guess, i've fully disabled image optimization. And it isn't a right solution for this issue.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/pagespeed/ngx_pagespeed/issues/1212#issuecomment-225064868, or mute the thread https://github.com/notifications/unsubscribe/AB2kPXfgS2Oy95V0KvsY8qKMNAJaB-FJks5qKK-SgaJpZM4IygRC .

n0guest commented 8 years ago

Hi -- I'm not sure what you have MaxImageRewritesAtOnce set to,

Nope, i didn't touch this parameter (i.e. it's on default value = 8). Is there any other information, that i can provide to help solving this issue? We've solved it by removing huge page, which i mentioned before. But, i guess, someone else can face exactly same problem. That's why i'm asking about providing any additional information.

hillsp commented 8 years ago

I'm surprised we wind up allocating so much memory. Are any of the images large (though at 35k I'd guess not)? The profile you linked looks like it's for CPU usage, so it's doesn't help us figure out what's going on here. Really what we'd need is a heap profile.

My guess is that we wind up allocating a lot of stuff when hit with all the rewrites and its causing some sort of memory fragmentation, which is a pain to debug. Is this suddenly a problem with a newer nginx pagespeed or have you simply never tried this before?

n0guest commented 8 years ago

Are any of the images large (though at 35k I'd guess not)?

It's hard to say, because we eliminated this abnormal page as soon as we found it. But i'm sure, that there weren't really huge images (10Mb or more). It's just pictures of products in internet shop.

Really what we'd need is a heap profile.

Could you exlain it or share the link with example how to do it? I can try to reproduce this enviroment on some heavy pages. BTW, nginx still consumes more memory comparing to "just after restart" values.

Is this suddenly a problem with a newer nginx pagespeed or have you simply never tried this before?

First time we faced this problem with nginx 1.9.x and ngx_pagespeed 1.10.33. We decided to update it and in first message i posted current versions of nginx and ngx_pagespeed. As i understand, both versions combinations are affected by this bug.