Which version of Squid are you using again? I patched the latest Squid-2.HEAD with some aufs related fixes that reduce the amount of callback checking which is done. Uhm, check src/fs/aufs/store_asyncufs.h : /* Which operations to run async */ #define ASYNC_OPEN 1 #define ASYNC_CLOSE 0 #define ASYNC_CREATE 1 #define ASYNC_WRITE 0 #define ASYNC_READ 1 Thats by default on Squid-2.HEAD. I've just changed them all to be async under cacheboy-1.6 and this performs great under freebsd-7 + AUFS with my testing. Adrian 2008/12/11 Bin Liu <binliu.lqbn@xxxxxxxxx>: > Thanks for your reply, Adrian. I'm very appreciated for your help. > >> I'd suggest using your OS profiling to figure out where the CPU is >> being spent. This may be a symptom, not the cause. > > Here is the top output snapshot: > > last pid: 76181; load averages: 1.15, 1.12, 1.08 up 6+05:35:14 22:25:07 > 184 processes: 5 running, 179 sleeping > CPU states: 24.2% user, 0.0% nice, 3.8% system, 0.0% interrupt, 72.0% idle > Mem: 4349M Active, 2592M Inact, 599M Wired, 313M Cache, 214M Buf, 11M Free > Swap: 4096M Total, 4096M Free > > PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND > 38935 nobody 27 44 0 4385M 4267M ucond 1 302:19 100.00% squid > 46838 root 1 44 0 24144K 2344K select 0 3:09 0.00% snmpd > 573 root 1 44 0 4684K 608K select 0 0:34 0.00% syslogd > 678 root 1 44 0 24780K 4360K select 1 0:12 0.00% perl5.8.8 > 931 root 1 44 0 10576K 1480K select 0 0:11 0.00% sendmail > 871 root 1 44 0 20960K 508K select 3 0:08 0.00% sshd > 941 root 1 8 0 5736K 424K nanslp 2 0:03 0.00% cron > 14177 root 1 44 0 40620K 2648K select 0 0:02 0.00% httpd > > > # iostat 1 5 > tty da0 da1 da2 cpu > tin tout KB/t tps MB/s KB/t tps MB/s KB/t tps MB/s us ni sy in id > 4 75 28.86 5 0.13 41.08 22 0.88 40.01 42 1.66 6 0 4 0 89 > 0 230 22.86 7 0.16 21.33 6 0.12 44.78 23 1.00 23 0 4 0 73 > 0 77 16.00 1 0.02 51.56 27 1.35 40.38 48 1.88 22 0 6 0 72 > 0 77 16.00 8 0.12 18.29 7 0.12 26.64 22 0.57 24 0 3 0 72 > 0 77 16.00 2 0.03 32.00 2 0.06 41.43 35 1.41 24 0 4 0 71 > > # vmstat 1 5 > procs memory page disks faults cpu > r b w avm fre flt re pi po fr sr da0 da1 in sy > cs us sy id > 1 2 0 13674764 386244 455 9 0 0 792 4672 0 0 4147 6847 > 6420 6 4 89 > 1 1 0 13674764 383112 1365 4 0 0 147 0 2 4 5678 9065 > 16860 18 6 76 > 1 1 0 13674764 383992 894 3 0 0 916 0 5 6 5089 7950 > 16239 22 5 73 > 1 1 0 13674764 378624 1399 11 0 0 52 0 11 1 5533 10447 > 18994 23 5 72 > 1 1 0 13674768 373360 1427 6 0 0 30 0 9 3 5919 10913 > 19686 25 5 70 > > > ASYNC IO Counters: > Operation # Requests > open 2396837 > close 1085 > cancel 2396677 > write 3187 > read 16721807 > stat 0 > unlink 299208 > check_callback 800440690 > queue 14 > > > I've noticed that the counter 'queue' is relatively high, which > normally should always be zero. But the disks seems pretty idle. I've > tested that by copying some large files to cache_dir, very fast. So > there must be something blocking squid. I've got 2 boxes with the same > hardware/software configuration running load balancing, when one of > them was blocking, another one ran pretty well. > > I'm using FreeBSD 7.0 + AUFS, and I've also noticed what you have > written several days ago > (http://www.squid-cache.org/mail-archive/squid-users/200811/0647.html), > which mentions that some operations may block under FreeBSD. So could > that cause this problem? > > Thanks again. > > Regards, > Liu > > > On Tue, Dec 9, 2008 at 23:28, Adrian Chadd <adrian@xxxxxxxxxxxxxxx> wrote: >> Its a hack which is done to defer a storage manager transaction from >> beginning whilst another one is in progress for that same connection. >> >> I'd suggest using your OS profiling to figure out where the CPU is >> being spent. This may be a symptom, not the cause. >> >> >> adrian >> >> 2008/12/7 Bin Liu <binliu.lqbn@xxxxxxxxx>: >>> Hi there, >>> >>> Squid is pegging CPU to 100% with "storeClientCopyEvent" and hit >>> service time soar up to server seconds here. The following is what I >>> see in cachemgr:events: >>> >>> OperationNext ExecutionWeightCallback Valid? >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent-0.019010 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> storeClientCopyEvent0.000000 seconds0yes >>> MaintainSwapSpace0.980990 seconds1N/A >>> idnsCheckQueue1.000000 seconds1N/A >>> ipcache_purgelru5.457004 seconds1N/A >>> wccp2HereIam5.464900 seconds1N/A >>> fqdncache_purgelru5.754399 seconds1N/A >>> storeDirClean10.767635 seconds1N/A >>> statAvgTick59.831274 seconds1N/A >>> peerClearRR110.539127 seconds0N/A >>> peerClearRR279.341239 seconds0N/A >>> User Cache Maintenance1610.136367 seconds1N/A >>> storeDigestRebuildStart1730.225879 seconds1N/A >>> storeDigestRewriteStart1732.267852 seconds1N/A >>> peerRefreshDNS1957.777934 seconds1N/A >>> peerDigestCheck2712.910515 seconds1yes >>> >>> So what does "storeClientCopyEvent" mean? Is it disk IO cause this problem? >>> >>> Regards, >>> Liu >>> >>> >> > > > > -- > Bin LIU > GreenCache Team, > Gforce Inc. > >
