Varnish 4 Performance Issues

Guillaume Quintard guillaume at varnish-software.com
Thu Sep 27 14:53:11 UTC 2018


But hit-for-pass, by default marks the object as uncacheable for two
minutes, so you should have issue for too long.

The problem you describe really looks like requests serialization stemming
from a lack of hit-for-pass.

But glad to read that it's over.

On Thu, Sep 27, 2018, 15:57 Junaid Mukhtar <junaid.mukhtar at gmail.com> wrote:

> We found the issue, it was Hit-for-Pass :(
>
> a lot of the non-cacheable URLs were being queued in VCL_Hash and that was
> causing varnish to slow down. We forced them to pass directly and this
> caused masive performance improvements and cache hit ratio jumped up as well
>
> --------
> Regards,
> Junaid
>
>
> On Wed, Sep 26, 2018 at 4:16 PM Guillaume Quintard <
> guillaume at varnish-software.com> wrote:
>
>> Getting a lot of Hit-for-Pass?
>>
>> Are you doing something like setting the ttl to 0s by any chance?
>> --
>> Guillaume Quintard
>>
>>
>> On Wed, Sep 26, 2018 at 4:55 PM Junaid Mukhtar <junaid.mukhtar at gmail.com>
>> wrote:
>>
>>> Interestingly we are seeing a lot of time in WaitingList before going to
>>> VCL Fetch
>>>
>>> -   VCL_return     hash
>>> -   VCL_call       HASH
>>> -   VCL_return     lookup
>>> -   Timestamp      Waitinglist: 1537973412.501378 2.410131 2.409963
>>> -   VCL_call       MISS
>>> -   VCL_return     fetch
>>> -   Link           bereq 22354816 fetch
>>> -   Timestamp      Fetch: 1537973412.505995 2.414748 0.004617
>>>
>>>
>>> --------
>>> Regards,
>>> Junaid
>>>
>>>
>>> On Wed, Sep 26, 2018 at 9:31 AM Junaid Mukhtar <junaid.mukhtar at gmail.com>
>>> wrote:
>>>
>>>> I totally agree about that.
>>>>
>>>> what we have figured out is that during the steady periods of
>>>> performance tests it run absolutely fine; but as soon as we spike up the
>>>> traffic (double the normal peak) performance degrades dramatically.
>>>>
>>>>
>>>> --------
>>>> Regards,
>>>> Junaid
>>>>
>>>>
>>>> On Tue, Sep 25, 2018 at 5:17 PM Guillaume Quintard <
>>>> guillaume at varnish-software.com> wrote:
>>>>
>>>>> without the vcl (and/or logs, but I'm assuming those are even more
>>>>> confidential), that's a tough cookie to debug
>>>>> --
>>>>> Guillaume Quintard
>>>>>
>>>>>
>>>>> On Mon, Sep 24, 2018 at 10:35 AM Junaid Mukhtar <
>>>>> junaid.mukhtar at gmail.com> wrote:
>>>>>
>>>>>> Hi
>>>>>>
>>>>>> Apologies but I am not allowed to share the VCL. If there's any other
>>>>>> thing like stats etc that might be helpful then do let me know
>>>>>>
>>>>>> --------
>>>>>> Regards,
>>>>>> Junaid
>>>>>>
>>>>>>
>>>>>> On Fri, Sep 21, 2018 at 4:15 PM Guillaume Quintard <
>>>>>> guillaume at varnish-software.com> wrote:
>>>>>>
>>>>>>> would you be able to share your vcl?
>>>>>>> --
>>>>>>> Guillaume Quintard
>>>>>>>
>>>>>>>
>>>>>>> On Fri, Sep 21, 2018 at 4:54 PM Junaid Mukhtar <
>>>>>>> junaid.mukhtar at gmail.com> wrote:
>>>>>>>
>>>>>>>> Any help guys; this is really getting to us.....
>>>>>>>>
>>>>>>>> --------
>>>>>>>> Regards,
>>>>>>>> Junaid
>>>>>>>>
>>>>>>>>
>>>>>>>> On Thu, Sep 20, 2018 at 3:57 PM Junaid Mukhtar <
>>>>>>>> junaid.mukhtar at gmail.com> wrote:
>>>>>>>>
>>>>>>>>>
>>>>>>>>> This is what we get in varnishhist
>>>>>>>>>
>>>>>>>>> 280_
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>                                      |
>>>>>>>>> 230_                                 |
>>>>>>>>>                                      |
>>>>>>>>>                                      |
>>>>>>>>>                                      |
>>>>>>>>>                                      |
>>>>>>>>> 180_                                 |
>>>>>>>>>                                     ||
>>>>>>>>>                                     ||
>>>>>>>>>                                     |||
>>>>>>>>>                                     |||
>>>>>>>>> 130_                                |||
>>>>>>>>>                                     |||
>>>>>>>>>                                    ||||||
>>>>>>>>>                                    ||||||
>>>>>>>>>                                    ||||||
>>>>>>>>> 80_                                ||||||
>>>>>>>>>
>>>>>>>>> ||||||                                                               #
>>>>>>>>>
>>>>>>>>> ||||||                                                               ###
>>>>>>>>>
>>>>>>>>> |||||||                                                             # ###
>>>>>>>>>
>>>>>>>>> |||||||||                                                           ##### #
>>>>>>>>> 30_
>>>>>>>>> |||||||||                                                           ########
>>>>>>>>>
>>>>>>>>> |||||||||
>>>>>>>>> #########
>>>>>>>>>
>>>>>>>>> ||||||||||
>>>>>>>>> ###########
>>>>>>>>>
>>>>>>>>> ||||||||||||                                                ## #
>>>>>>>>> #############       #
>>>>>>>>>
>>>>>>>>> +---------------------+---------------------+---------------------+---------------------+---------------------+---------------------+---------------------+---------------------+---------------------
>>>>>>>>> |1e-6                 |1e-5                 |1e-4
>>>>>>>>> |1e-3                 |1e-2                 |1e-1
>>>>>>>>> |1e0                  |1e1                  |1e2
>>>>>>>>> --------
>>>>>>>>> Regards,
>>>>>>>>> Junaid
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On Thu, Sep 20, 2018 at 3:54 PM Junaid Mukhtar <
>>>>>>>>> junaid.mukhtar at gmail.com> wrote:
>>>>>>>>>
>>>>>>>>>> Below is the output; all of them are default except i was trying
>>>>>>>>>> to up the threads_pool to 4 but didn't feel any imporvement in performance
>>>>>>>>>> degradation
>>>>>>>>>>
>>>>>>>>>> accept_filter              off [bool] (default)
>>>>>>>>>> acceptor_sleep_decay       0.9 (default)
>>>>>>>>>> acceptor_sleep_incr        0.000 [seconds] (default)
>>>>>>>>>> acceptor_sleep_max         0.050 [seconds] (default)
>>>>>>>>>> auto_restart               on [bool] (default)
>>>>>>>>>> backend_idle_timeout       60.000 [seconds] (default)
>>>>>>>>>> ban_dups                   on [bool] (default)
>>>>>>>>>> ban_lurker_age             60.000 [seconds] (default)
>>>>>>>>>> ban_lurker_batch           1000 (default)
>>>>>>>>>> ban_lurker_sleep           0.010 [seconds] (default)
>>>>>>>>>> between_bytes_timeout      60.000 [seconds] (default)
>>>>>>>>>> cc_command                 "exec gcc -std=gnu99  -O2 -g
>>>>>>>>>> -Wp,-D_FORTIFY_SOURCE=0 -Wall -Werror -pthread -fpic -shared -Wl,-x -o %o
>>>>>>>>>> %s" (default)
>>>>>>>>>> cli_buffer                 8k [bytes] (default)
>>>>>>>>>> cli_limit                  48k [bytes] (default)
>>>>>>>>>> cli_timeout                60.000 [seconds] (default)
>>>>>>>>>> clock_skew                 10 [seconds] (default)
>>>>>>>>>> clock_step                 1.000 [seconds] (default)
>>>>>>>>>> connect_timeout            3.500 [seconds] (default)
>>>>>>>>>> critbit_cooloff            180.000 [seconds] (default)
>>>>>>>>>> debug                      none (default)
>>>>>>>>>> default_grace              10.000 [seconds] (default)
>>>>>>>>>> default_keep               0.000 [seconds] (default)
>>>>>>>>>> default_ttl                120.000 [seconds] (default)
>>>>>>>>>> feature                    none (default)
>>>>>>>>>> fetch_chunksize            16k [bytes] (default)
>>>>>>>>>> fetch_maxchunksize         0.25G [bytes] (default)
>>>>>>>>>> first_byte_timeout         60.000 [seconds] (default)
>>>>>>>>>> gzip_buffer                32k [bytes] (default)
>>>>>>>>>> gzip_level                 6 (default)
>>>>>>>>>> gzip_memlevel              8 (default)
>>>>>>>>>> http_gzip_support          on [bool] (default)
>>>>>>>>>> http_max_hdr               64 [header lines] (default)
>>>>>>>>>> http_range_support         on [bool] (default)
>>>>>>>>>> http_req_hdr_len           8k [bytes] (default)
>>>>>>>>>> http_req_size              32k [bytes] (default)
>>>>>>>>>> http_resp_hdr_len          8k [bytes] (default)
>>>>>>>>>> http_resp_size             32k [bytes] (default)
>>>>>>>>>> idle_send_timeout          60.000 [seconds] (default)
>>>>>>>>>> listen_depth               1024 [connections] (default)
>>>>>>>>>> lru_interval               2.000 [seconds] (default)
>>>>>>>>>> max_esi_depth              5 [levels] (default)
>>>>>>>>>> max_restarts               4 [restarts] (default)
>>>>>>>>>> max_retries                4 [retries] (default)
>>>>>>>>>> nuke_limit                 50 [allocations] (default)
>>>>>>>>>> pcre_match_limit           10000 (default)
>>>>>>>>>> pcre_match_limit_recursion 20 (default)
>>>>>>>>>> ping_interval              3 [seconds] (default)
>>>>>>>>>> pipe_timeout               60.000 [seconds] (default)
>>>>>>>>>> pool_req                   10,100,10 (default)
>>>>>>>>>> pool_sess                  10,100,10 (default)
>>>>>>>>>> pool_vbo                   10,100,10 (default)
>>>>>>>>>> prefer_ipv6                off [bool] (default)
>>>>>>>>>> rush_exponent              3 [requests per request] (default)
>>>>>>>>>> send_timeout               600.000 [seconds] (default)
>>>>>>>>>> session_max                100000 [sessions] (default)
>>>>>>>>>> shm_reclen                 255b [bytes] (default)
>>>>>>>>>> shortlived                 10.000 [seconds] (default)
>>>>>>>>>> sigsegv_handler            on [bool] (default)
>>>>>>>>>> syslog_cli_traffic         on [bool] (default)
>>>>>>>>>> tcp_fastopen               off [bool] (default)
>>>>>>>>>> tcp_keepalive_intvl        75.000 [seconds] (default)
>>>>>>>>>> tcp_keepalive_probes       9 [probes] (default)
>>>>>>>>>> tcp_keepalive_time         7200.000 [seconds] (default)
>>>>>>>>>> thread_pool_add_delay      0.000 [seconds] (default)
>>>>>>>>>> thread_pool_destroy_delay  1.000 [seconds] (default)
>>>>>>>>>> thread_pool_fail_delay     0.200 [seconds] (default)
>>>>>>>>>> thread_pool_max            5000 [threads] (default)
>>>>>>>>>> thread_pool_min            100 [threads] (default)
>>>>>>>>>> thread_pool_reserve        0 [threads] (default)
>>>>>>>>>> thread_pool_stack          48k [bytes] (default)
>>>>>>>>>> thread_pool_timeout        300.000 [seconds] (default)
>>>>>>>>>> thread_pools               2 [pools] (default)
>>>>>>>>>> thread_queue_limit         20 (default)
>>>>>>>>>> thread_stats_rate          10 [requests] (default)
>>>>>>>>>> timeout_idle               5.000 [seconds] (default)
>>>>>>>>>> timeout_linger             0.050 [seconds] (default)
>>>>>>>>>> vcc_allow_inline_c         off [bool] (default)
>>>>>>>>>> vcc_err_unref              on [bool] (default)
>>>>>>>>>> vcc_unsafe_path            on [bool] (default)
>>>>>>>>>> vcl_cooldown               600.000 [seconds] (default)
>>>>>>>>>> vcl_dir                    /etc/varnish (default)
>>>>>>>>>> vmod_dir                   /usr/lib64/varnish/vmods (default)
>>>>>>>>>> vsl_buffer                 4k [bytes] (default)
>>>>>>>>>> vsl_mask                   -VCL_trace,-WorkThread,-Hash,-VfpAcct
>>>>>>>>>> (default)
>>>>>>>>>> vsl_reclen                 255b [bytes] (default)
>>>>>>>>>> vsl_space                  80M [bytes] (default)
>>>>>>>>>> vsm_free_cooldown          60.000 [seconds] (default)
>>>>>>>>>> vsm_space                  1M [bytes] (default)
>>>>>>>>>> workspace_backend          64k [bytes] (default)
>>>>>>>>>> workspace_client           64k [bytes] (default)
>>>>>>>>>> workspace_session          0.50k [bytes] (default)
>>>>>>>>>> workspace_thread           2k [bytes] (default)
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> --------
>>>>>>>>>> Regards,
>>>>>>>>>> Junaid
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> On Thu, Sep 20, 2018 at 3:37 PM Dridi Boukelmoune <dridi at varni.sh>
>>>>>>>>>> wrote:
>>>>>>>>>>
>>>>>>>>>>> On Thu, Sep 20, 2018 at 4:14 PM Junaid Mukhtar <
>>>>>>>>>>> junaid.mukhtar at gmail.com> wrote:
>>>>>>>>>>> >
>>>>>>>>>>> > Hi
>>>>>>>>>>> >
>>>>>>>>>>> > we are in middle of upgrading from varnish 3.0.7 to varnish
>>>>>>>>>>> 4.1.10; but unfortunately all of the response times in the performance test
>>>>>>>>>>> are indicating an increase of at least 100%
>>>>>>>>>>> >
>>>>>>>>>>> > We have analyzed the logs and everything but can't get around
>>>>>>>>>>> this; the issue is not only for the non-cached pages but it's also
>>>>>>>>>>> impacting the cached pages. We are also struggling to analyze it further as
>>>>>>>>>>> well, any guidenace as to what we can do in terms of putting debug logging
>>>>>>>>>>> in would be helpful.
>>>>>>>>>>> >
>>>>>>>>>>> > One of the areas we are considering is to output response
>>>>>>>>>>> times, but it's proving difficult for me. Any suggestions
>>>>>>>>>>>
>>>>>>>>>>> Hello,
>>>>>>>>>>>
>>>>>>>>>>> What is the output of `varnishadm param.show` ?
>>>>>>>>>>>
>>>>>>>>>>> Dridi
>>>>>>>>>>>
>>>>>>>>>> _______________________________________________
>>>>>>>> varnish-misc mailing list
>>>>>>>> varnish-misc at varnish-cache.org
>>>>>>>> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>>>>>>>>
>>>>>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20180927/e4f25105/attachment-0001.html>


More information about the varnish-misc mailing list