Skip site navigation (1)Skip section navigation (2)
Date:      Tue, 12 Dec 2006 13:11:36 +0900
From:      "Adrian Chadd" <adrian@freebsd.org>
To:        "Joseph Koshy" <joseph.koshy@gmail.com>
Cc:        freebsd-hackers@freebsd.org
Subject:   Re: pmcstat and squid
Message-ID:  <d763ac660612112011m4b40efe3ud32983291906f724@mail.gmail.com>
In-Reply-To: <84dead720612112006r5573a04fge2664ffe3a93f796@mail.gmail.com>
References:  <d763ac660612111955p6dc85a8ufca9ff3b78e3f376@mail.gmail.com> <84dead720612112006r5573a04fge2664ffe3a93f796@mail.gmail.com>

next in thread | previous in thread | raw e-mail | index | archive | help
On 12/12/06, Joseph Koshy <joseph.koshy@gmail.com> wrote:
>
> I can think of one of two scenarios:
>
>  1) the squid process was in the kernel when the
>     samples got taken.  This could happen if the
>     process was say in select() handling all the time.
>  2) There a bug in my process handling code that is
>     being triggered (hwpmc undercounts process-mode
>     samples), and samples are being missed.

I can't imagine why Squid would suddenly be in kernel mode all the time.
In fact, its in kernel space about 20% of the time under this workload
(with another 30% spent in interrupts.)

Here's the output from my latest attempt:
jacinta# pmcstat -S instructions -O samples.out
^Cjacinta# ls -l
total 89650
-rw-r--r--  1 root  wheel       576 Dec 12 03:52 1
-rw-r--r--  1 root  wheel  91719744 Dec 12 04:10 samples.out
jacinta# pmcstat -R samples.out -g
jacinta# cd k7-retired-instructions/
jacinta# ls
kernel.gmon             ld-elf.so.1.gmon        libc.so.6.gmon
jacinta# ls -l
total 3116
-rw-r--r--  1 root  wheel  2704268 Dec 12 04:10 kernel.gmon
-rw-r--r--  1 root  wheel    59474 Dec 12 04:10 ld-elf.so.1.gmon
-rw-r--r--  1 root  wheel   372962 Dec 12 04:10 libc.so.6.gmon

Squid is running but there's no profiling information for it still..

Scarily, on this Athlon 1800XP:

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
  5.1   45254.00 45254.00                             SHA256_Transform [1]
  4.0   81184.00 35930.00                             tcp_input [2]
  3.8  114879.00 33695.00                             tcp_output [3]
  2.8  139645.00 24766.00                             critical_exit [4]
  2.5  162199.00 22554.00
bus_dmamap_load_mbuf_sg [5]
  2.3  182415.00 20216.00                             generic_bzero [6]
  2.1  201156.00 18741.00                             kqueue_register [7]

The kernel spends quite a bit of time in SHA256_Transform; I wonder if
it has to do with the sheer volume of TCP connections I'm making..



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?d763ac660612112011m4b40efe3ud32983291906f724>