Re: [squid-users] "Quadruple" memory usage with squid

The result of the test with vm.pmap.pg_ps_enabled set to 1
is ... different than what I expected.
The values of vm.pmap.pde.p_failures and vm.pmap.pde.demotions
indicate that the page daemon has problems creating and
maintaining superpages. Maybe the load is too high
to create superpages or the algorithm of the page daemon
needs to be tuned.

Perhaps the FreeBSD list can offer more assistance
on the question of superpages and give an explanation
for the high values for vm.pmap.pde.p_failures and
vm.pmap.pde.demotions...
But one last try from me: The machine has 24 GB and Squid has
19 GB. I guess that on the first fork the OS demotes many
superpages because it needs to map the child process to
virtual memory and superpages cannot be swapped and therefore
will be demoted. The second fork demotes more superpages...
To make the first fork fast, Squid must be
less than 10 GB because Squid and its child fit within
physical memory. You will need a low value for
sleep_after_fork to do the exec before the next fork is
executed.

There are alternative solutions to the problem:
1. redesign the URL rewriter into a multithreaded application that
accepts multiple requests from Squid simultaneously (use
url_rewrite_concurrency in squid.conf)
This way there will be only one child process and only one fork on
'squid -k rotate'
2. redesign the URL rewriter where the URL rewriter rereads
its configuration/database on receipt of a signal and
send this signal every 24 hours without doing the 'squid -k rotate'
This way squid does not fork.
(maybe you want a 'squid -k rotate' once per week though).
3. modify the URL rewriter to accept multiple request
simultaneously (use url_rewrite_concurrency 4) and reduce the
number of rewriter to 4. The URL rewritor will not be modified
to be multithreaded but simply queues the requests.
This way Squid does only 4 forks instead of 15.
4. use less URL rewriters. You might get an occasional
'not enough rewriters' warning from Squid in which case the
redirector might be bypassed (use url_rewrite_bypass).
Depending on what exactly the URL rewriter does, this
might be acceptable.
This way Squid does less forks.

option 1 requires a lot of work and is probable the best solution.
option 2 requires a lot of work and and is less robust than option 1
because at the time of the reconfiguration it cannot serve requests from Squid.
option 3 is most likely very simple but it is unknown how much it helps.
option 4 is simple, but depending on the functionality
of the rewriter, it is or is not acceptable. You need to experiment
to see if it helps.

Marcus

Linda Messerschmidt wrote:
> On Tue, Nov 24, 2009 at 9:52 PM, Marcus Kool
> <marcus.kool_at_urlfilterdb.com> wrote:
>> Linda started this thread with huge performance problems
>> when Squid with a size of 12 GB forks 15 times.
>
> I'm still not convinced that our memory usage is correct. Here's
> where the cache_mem 10GB process is at right now:
>
> Maximum Resident Size: 19376000 KB
> Total accounted: 9735764 KB
> Storage Mem size: 9296872 KB
> 338229 StoreEntries
> 338229 StoreEntries with MemObjects
>
> So there is (9735764 - 9296872) 438,892 KB "overhead" (memory
> accounted for that is not used for storing objects) and (19376000 -
> 9735764) 9,640,236 KB "unaccounted."
>
> I will put the whole memory report at the bottom of this message
> though it is very hard to read. :-)
>
>> Linda emailed me that she is doing a test with
>> vm.pmap.pg_ps_enabled set to 1 (the kernel will
>> transparently transform 4K pages into superpages)
>> which gives a big relief for TLB management
>> and will most likely reduce performance problems with
>> forks of very large processes.
>
> I apologize I meant to send that to the whole list.
>
> In any case, it did not help. This is from top while it was doing
> daily rotation a few moments ago:
>
>
> PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND
> 1205 squid 1 118 0 18650M 18675M CPU6 1 57:22 97.85% squid
> 74418 squid 1 118 0 16259M 24K CPU2 2 0:05 97.66% squid
>
> It doesn't look like the superpages enabled had a lot of effect:
>
> $ sysctl vm.pmap
> vm.pmap.pmap_collect_active: 0
> vm.pmap.pmap_collect_inactive: 0
> vm.pmap.pv_entry_spare: 6673
> vm.pmap.pv_entry_allocs: 105465793
> vm.pmap.pv_entry_frees: 100913786
> vm.pmap.pc_chunk_tryfail: 0
> vm.pmap.pc_chunk_frees: 610560
> vm.pmap.pc_chunk_allocs: 637695
> vm.pmap.pc_chunk_count: 27135
> vm.pmap.pv_entry_count: 4552007 <--------
> vm.pmap.pde.promotions: 12657 <------
> vm.pmap.pde.p_failures: 222291
> vm.pmap.pde.mappings: 0
> vm.pmap.pde.demotions: 11968 <-------
> vm.pmap.shpgperproc: 200
> vm.pmap.pv_entry_max: 7330186
> vm.pmap.pg_ps_enabled: 1
>
> Here are similar readings from the 16GB machine, where the squid
> process has VSZ of 8599M:
>
> vm.pmap.pmap_collect_active: 0
> vm.pmap.pmap_collect_inactive: 0
> vm.pmap.pv_entry_spare: 16299
> vm.pmap.pv_entry_allocs: 2196230824
> vm.pmap.pv_entry_frees: 2193907723
> vm.pmap.pc_chunk_tryfail: 0
> vm.pmap.pc_chunk_frees: 13548719
> vm.pmap.pc_chunk_allocs: 13562644
> vm.pmap.pc_chunk_count: 13925
> vm.pmap.pv_entry_count: 2323101 <------------
> vm.pmap.pde.promotions: 0
> vm.pmap.pde.p_failures: 0
> vm.pmap.pde.mappings: 0
> vm.pmap.pde.demotions: 0
> vm.pmap.shpgperproc: 200
> vm.pmap.pv_entry_max: 4276871
> vm.pmap.pg_ps_enabled: 0
>
> Squid uses almost all of the memory in use on both systems, so the
> rough value of:
>
> No superpages: 2323101 / 8599 = 270 pages per MB
> Yes superpages: 4552007 / 18650 = 244 pages per MB
>
> That's not quite fair since it's the whole system's page table vs.
> squid's address space but these machines are all about squid so it's
> fair enough.
>
> I added up all the system's VSZ and divided it into the updated number
> of pages; the system average is just 4.554KB per page, so it seems
> like there must be barely any super pages in use, which is borne out
> by the (promotions - demotions) figure of (12657 - 11968) 689 active
> superpages. Assuming that means what I think it means.
>
>> can we modify Squid to fork at a slower pace?
>
> I think there is a config option (sleep_after_fork) for that already.
> But it would not help as the processes are already forked one at a
> time and the page table duplication happens before the exec. Even if
> it did help, sleep_after_fork would have to be several seconds, and
> squid would still be nonresponsive for sleep_after_fork * 16.
>
> It sounds like this problem is a bit more serious and complicated than
> I thought. I really hoped it was a config error on our part. :-(
>
> Here is the full memory report as the process VSZ crossed over to
> 19,001 MB, which shows a total of 9,317,346 KB in use:
>
> Current memory usage:
> Pool Obj Size Allocated In Use Idle Allocations Saved Hit Rate
> (bytes) (#) (KB) high (KB) high (hrs) impact (%total) (#)
> (KB) high (KB) portion (%alloc) (#) (KB) high (KB) (number)
> (%num) (%vol) (%num) (number)
> 2K Buffer 2048 96 192 248 0.52 0 91 182 248 95
> 5 10 94 34958835 4.42 18.12 99.96 34972340
> 4K Buffer 4096 199 796 3904 11.98 0 194 776 3904
> 97 5 20 1720 7225790 0.91 7.49 98.41 7342427
> 8K Buffer 8192 21 168 272 12.05 0 17 136 272 81
> 4 32 176 1880965 0.24 3.90 98.40 1911548
> 16K Buffer 16384 3 48 64 13.39 0 0 0 64 0 3 48
> 64 3600 0.00 0.01 98.41 3658
> 32K Buffer 32768 2 64 128 14.56 0 0 0 128 0 2
> 64 128 369 0.00 0.00 98.14 376
> 64K Buffer 65536 2 128 192 12.81 0 0 0 192 0 2
> 128 128 88 0.00 0.00 95.65 92
> Store Client Buffer 4096 22 88 1052 12.05 0 11 44 1052 50
> 11 44 812 30568572 3.87 31.69 99.74 30646811
> acl 64 11 1 1 15.35 0 11 1 1 100 0 0
> 1 11 0.00 0.00 50.00 22
> acl_ip_data 24 7 1 1 15.35 0 7 1 1 100 0 0 1
> 7 0.00 0.00 50.00 14
> acl_list 24 18 1 1 15.35 0 18 1 1 100 0 0
> 1 18 0.00 0.00 50.00 36
> dlink_node 24 337 8 8 0.52 0 0 0 8 0 337 8 8
> 1088 0.00 0.00 76.35 1425
> FwdServer 24 41 1 6 12.05 0 9 1 6 22 32 1 5
> 3875752 0.49 0.02 99.87 3880603
> HttpReply 168 338927 55606 55606 0.00 1 338922
> 55605 55606 100 5 1 23 10817354 1.37 0.46 96.17 11248509
> HttpHeaderEntry 40 2602377 101656 101656 0.00 1 2602282
> 101652 101656 100 95 4 101 200511069 25.36 2.03 98.06
> 204487269
> HttpHdrCc 40 27921 1091 1091 0.01 0 27914 1091
> 1091 100 7 1 3 7294400 0.92 0.07 99.17 7355123
> HttpHdrRangeSpec 16 96 2 2 13.43 0 0 0 2 0 96 2 2
> 25596 0.00 0.00 99.31 25775
> HttpHdrRange 16 2 1 1 12.07 0 0 0 1 0 2 1 1
> 21759 0.00 0.00 99.44 21881
> HttpHdrContRange 24 5 1 1 13.46 0 0 0 1 0 5 1 1
> 10713 0.00 0.00 97.21 11021
> intlist 16 3 1 1 15.35 0 3 1 1 100 0 0 1
> 3 0.00 0.00 50.00 6
> MemObject 272 338920 90026 90026 0.00 1 338915
> 90025 90026 100 5 2 39 5022931 0.64 0.35 93.21 5388889
> mem_node 4112 2338883 9392078 9392078 0.00 96
> 2338871 9392029 9392078 100 12 49 3908 15349368 1.94 15.98
> 81.20 18902877
> relist 48 8 1 1 15.35 0 8 1 1 100 0 0 1
> 8 0.00 0.00 50.00 16
> request_t 1360 341 453 893 12.05 0 326 433 893
> 96 15 20 496 9456631 1.20 3.26 98.60 9590792
> StoreEntry 88 338920 29126 29126 0.00 0 338915
> 29126 29126 100 5 1 13 5025544 0.64 0.11 93.26 5388889
> wordlist 16 14 1 1 15.35 0 11 1 1 79 3 1 1
> 88 0.00 0.00 86.27 102
> ClientInfo 344 28096 9439 14657 12.40 0 15714 5279
> 14657 56 12382 4160 4852 653528 0.08 0.06 93.63 697962
> MD5 digest 16 338920 5296 5296 0.00 0 338915 5296
> 5296 100 5 1 3 13112283 1.66 0.05 97.40 13462778
> helper_request 40 353 14 14 0.52 0 1 1 14 0 352
> 14 14 4805587 0.61 0.05 99.99 4805971
> storeSwapTLV 24 5 1 1 15.32 0 0 0 1 0 5 1 1
> 47627493 6.02 0.29 100.00 47627498
> Short Strings 36 2939320 103336 103336 0.00 1 2939241
> 103333 103336 100 79 3 75 219162796 27.72 2.00 98.15
> 223283726
> Medium Strings 128 15166 1896 1951 0.52 0 15126 1891
> 1951 100 40 5 89 50029245 6.33 1.62 99.39 50334410
> Long Strings 512 5927 2964 3002 0.52 0 5911 2956
> 3002 100 16 8 143 9251916 1.17 1.20 99.22 9325056
> cbdata acl_access (1) 56 13 1 1 15.35 0 13 1 1 100 0 0
> 1 13 0.00 0.00 50.00 26
> cbdata aclCheck_t (2) 312
> daf
> 1 1 1 15.32 0 0 0 1 0 1 1 1 22575783 2.86 1.78 100.00 22575832
> cbdata clientHttpRequest (3) 1096 21 23 481 0.52 0 15 17 481
> 71 6 7 387 4735510 0.60 1.31 98.21 4821935
> cbdata ConnStateData (4) 320 194 61 299 11.98 0 190 60 299
> 98 4 2 137 2604058 0.33 0.21 97.41 2673373
> cbdata ErrorState (5) 160 200 32 32 0.06 0 199 32 32 100
> 1 1 1 16266 0.00 0.00 98.79 16466
> cbdata FwdState (6) 96 31 3 24 12.05 0 9 1 24 29 22 3
> 20 3871284 0.49 0.09 99.76 3880603
> cbdata generic_cbdata (7) 32 30 1 4 15.32 0 0 0 4 0 30
> 1 4 14750620 1.87 0.12 100.00 14750938
> cbdata helper (8) 136 1 1 1 15.35 0 1 1 1 100 0 0 0
> 0 0.00 0.00 0.00 1
> cbdata helper_server (9) 152 16 3 3 15.35 0 16 3 3 100 0
> 0 3 32 0.00 0.00 66.67 48
> cbdata HttpStateData (12) 152 38 6 37 12.05 0 9 2 37 24
> 29 5 32 3874204 0.49 0.15 99.85 3880194
> cbdata ps_state (14) 200 1 1 1 15.32 0 0 0 1 0 1 1 1
> 3880602 0.49 0.20 100.00 3880603
> cbdata RemovalPolicy (15) 104 1 1 1 15.35 0 1 1 1 100 0
> 0 0 0 0.00 0.00 0.00 1
> cbdata store_client (18) 128 167 21 45 12.05 0 133 17 45
> 80 34 5 29 8643422 1.09 0.28 99.89 8652735
> event 48 34 2 3 12.38 0 31 2 3 91 3 1 1
> 8007262 1.01 0.10 99.96 8010458
> cbdata http_port_list (19) 128 2 1 1 14.75 0 2 1 1 100 0
> 0 0 0 0.00 0.00 0.00 2
> cbdata body_size (20) 64 1 1 1 15.35 0 1 1 1 100 0 0 1
> 1 0.00 0.00 50.00 2
> cbdata ConnectStateData (21) 96 16 2 11 15.32 0 0 0 11 0
> 16 2 11 3826157 0.48 0.09 99.96 3827561
> close_handler 24 236 6 31 12.05 0 224 6 31 95 12
> 1 13 14200692 1.80 0.09 99.57 14261946
> ipcache_entry 128 978 123 137 13.32 0 951 119 137
> 97 27 4 22 611237 0.08 0.02 98.86 618298
> fqdncache_entry 160 20 4 4 15.35 0 20 4 4 100 0 0
> 4 24 0.00 0.00 54.55 44
> cbdata idns_query (22) 8680 2 17 941 15.32 0 0 0 941 0 2
> 17 941 616884 0.08 1.36 99.78 618218
> cbdata redirectStateData (23) 72 353 25 25 0.52 0 1 1 25
> 0 352 25 25 4805595 0.61 0.09 99.99 4805971
> cbdata Logfile (26) 1120 3 4 4 15.35 0 3 4 4 100 0 0 4
> 3 0.00 0.00 50.00 6
> pconn_data 32 6 1 1 13.34 0 1 1 1 17 5 1 1
> 61876 0.01 0.00 99.69 62069
> pconn_fds 32 6 1 1 13.34 0 1 1 1 17 5 1 1
> 61889 0.01 0.00 99.71 62069
> cbdata AddVaryState (29) 160 1 1 2 12.38 0 0 0 2 0 1 1
> 2 305954 0.04 0.01 99.84 306435
> cbdata LocateVaryState (30) 136 3 1 1 12.38 0 0 0 1 0 3
> 1 1 571615 0.07 0.02 99.99 571661
> VaryData 32 6 1 1 13.62 0 1 1 1 17 5 1 1
> 570046 0.07 0.00 99.72 571661
> cbdata StoreUpdateState (31) 4152 2 9 41 12.34 0 0 0 41 0
> 2 9 41 1044654 0.13 1.10 99.71 1047729
> Total - 9317346 9794810 9794810 0.00 100
> 9303255 9790117 9790185 100 14091 4693 5120 776329091 98.19
> 95.79 98.19 790614788
> Cumulative allocated volume: 395.07 GB
> Current overhead: 301304 bytes (0.003%)
> Idle pool limit: 5.00 MB
> memPoolAlloc calls: 790614788
> memPoolFree calls: 781311532
> String Pool Impact
> (%strings) (%volume)
> Short Strings 99 96
> Medium Strings 1 2
> Long Strings 0 3
> Other Strings 0 0
>
> Large buffers: 0 (0 KB)
>
> Are we 100% certain this is normal / correct? Cutting the process
> size in half would double the process spawn rate. :)
>
> Thanks!
>
>
Received on Wed Nov 25 2009 - 12:43:38 MST