Re: Beta 15 works! (but it's broken in a different way :)

From: Oskar Pearson <oskar@dont-contact.us>
Date: Tue, 17 Feb 1998 04:19:46 +0200

--MimeMultipartBoundary
Content-Type: text/plain; charset=us-ascii

Hi

> > squid@newt:/usr/local/squid/bin > time ./squid
> > real 3m10.029s
> > user 0m1.320s
> > sys 0m3.080s
> > huh?
> time ./squid -N ?

squid@newt:/usr/local/squid/bin > time ./squid -N

real 12m11.509s
user 0m44.030s
sys 2m2.150s

Not really true I would guess...

> > hmm... I should have used 'strace -f':
> >
> > hmm. That's just great... when I strace -f it doesn't chew CPU!
>
> Laugh. Try leaving it for a while. I've noticed that the children burn
Yeah - especially when you are starting with a new cache_dir the
machine goes crazy for quite a while.

 procs memory swap io system cpu
 r b w swpd free buff cache si so bi bo in cs us sy id
33 0 0 47308 712 1156 4616 0 0 45 32 394 153 26 74 0
34 0 0 47308 732 1216 4540 0 0 107 11 775 280 25 75 0
33 0 0 47308 716 1272 4500 0 0 59 14 286 157 29 71 0
33 0 0 47304 716 1312 4456 2 0 101 36 859 279 28 72 0
34 0 0 47304 716 1352 4416 0 0 80 0 272 188 21 79 0
33 0 0 47304 732 1404 4340 0 0 87 49 926 255 30 70 0
33 0 0 47304 716 1464 4288 0 0 146 4 675 324 30 70 0
33 0 0 47304 716 1464 4288 0 0 24 14 189 86 27 73 0
33 0 0 47304 716 1464 4288 0 0 84 33 586 240 26 74 0
26 0 0 47300 528 1288 4444 12 0 154 16 692 249 27 73 0
27 0 0 47300 852 1144 4468 0 0 17 18 555 126 30 70 0
<rapid drop in disk here... machine actually useable>
33 0 0 47300 800 1144 4468 0 0 1 6 387 63 24 76 0
27 0 0 47300 776 1144 4468 0 0 4 1 166 57 34 66 0
17 0 0 47300 704 1208 4468 0 0 2 0 205 95 31 69 0

I did earlier... it stops being sooo bad, but the load average doesn't
go below 10.. please let me know if this doesn't happen to you, since otherwise
it's probably libraries or something.

squid@newt:/usr/local/squid/bin > time ./squid -N

real 12m11.509s
user 0m44.030s
sys 2m2.150s

> Note that you can't strace a thread. And attempting to do so will stop
> it, so you need to 'kill -CONT <tid>' to keep things happy.
I presume the same applies to see what it's doing with gdb.. hmm. seems not.

214 ret = pthread_cond_timedwait(&(threadp->cond),
(gdb) n
217 }
(gdb) n
211 abstime.tv_sec = squid_curtime + 3;
(gdb) n
212 abstime.tv_nsec = 0;
(gdb) n
213 threadp->status = _THREAD_WAITING;
(gdb) n
214 ret = pthread_cond_timedwait(&(threadp->cond),
(gdb) n
217 }
(gdb) n
211 abstime.tv_sec = squid_curtime + 3;
(gdb) n
212 abstime.tv_nsec = 0;
(gdb) n
213 threadp->status = _THREAD_WAITING;
(gdb) n
214 ret = pthread_cond_timedwait(&(threadp->cond),
(gdb) n
217 }

and again and again and again.. If I had to guess it's since the thread is
marked as 'idle' and therefore doesn't do anything while I am gdbing it...
gprof...?

(gdb) bt
#0 aio_thread_loop (ptr=0x809c258) at aiops.c:213
#1 0x4000e2d0 in pthread_start_thread ()

> # ps uaxr
> USER PID %CPU %MEM SIZE RSS TTY STAT START TIME COMMAND
> root 4355 0.0 0.0 956 392 p3 R 09:36 0:00 ps uaxr
> squid 4247 69.6 41.7 217404 215196 ? R 09:14 14:59 /opt/s2/bin/squid -N -C
> squid 4260 0.4 41.7 217404 215196 ? D 09:14 0:05 /opt/s2/bin/squid -N -C
> squid 4261 0.3 41.7 217404 215196 ? D 09:14 0:04 /opt/s2/bin/squid -N -C

hmm. I have LOTS more threads running..

    USER PID %CPU %MEM VSZ RSS TT STAT START TIME COMMAND
newt:/usr/local/squid/logs # ps uaxr |grep squid
squid 29098 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29099 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29101 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29103 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29105 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29107 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29109 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29111 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29113 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29115 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29117 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29119 4.4 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29121 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29123 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29124 4.4 0.6 2100 196 q0 R 03:41 0:31 squid
squid 29125 4.5 0.6 2100 196 q0 R 03:41 0:31 squid
newt:/usr/local/squid/logs # date (10 minutes long enough?)
Tue Feb 17 03:53:10 SAT 1998

> Thats a 1.2b11 + patches, so it's not directly comparable. Is b15
> working for you other than burning CPU time? I might give it a shot
> again.
It seems too... I would run it on a quiet system though :)

hmm.

stats:~/overall-stats $ echoping-nocache -n 5 -h http://www.is.co.za/ newt:3128
HTTP error "HTTP/1.0 503 Service Unavailable

887681156.255 35 196.23.0.160 TCP_MISS/503 692 GET http://www.is.co.za/ - DIRECT/www.is.co.za -
887681161.981 34 196.23.0.160 TCP_MISS/503 692 GET http://www.is.co.za/ - DIRECT/www.is.co.za -

Oskar

---
"Haven't slept at all. I don't see why people insist on sleeping. You feel
so much better if you don't. And how can anyone want to lose a minute -
a single minute of being alive?"				-- Think Twice
--MimeMultipartBoundary--
Received on Tue Jul 29 2003 - 13:15:46 MDT

This archive was generated by hypermail pre-2.1.9 : Tue Dec 09 2003 - 16:11:42 MST