Greetings, Hopefully, I can save someone a few hours of heartache. Summary: If you plan to use squid on solaris 10 x86, and configure to use /dev/poll, make sure its patched. Thanks everyone for reading the spam below if you did. ---------- Forwarded message ---------- From: Frank Ruiz <frank.ruiz@xxxxxxxxx> Date: Oct 5, 2007 12:18 PM Subject: 2 instances To: squid-users <squid-users@xxxxxxxxxxxxxxx> Also, Just killed all connections to squid process. CPU still pegged at 15% and decreasing Here is what the process is doing: ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 1 accept(8, 0xFFFFFD7FFFDFFB90, 0xFFFFFD7FFFDFFB7C, SOV_DEFAULT) = 12 getsockname(12, 0xFFFFFD7FFFDFFB80, 0xFFFFFD7FFFDFFB7C, SOV_DEFAULT) = 0 fcntl(12, F_GETFL) = 130 fcntl(12, F_SETFD, 0x00000083) = 0 fcntl(12, F_GETFL) = 130 fcntl(12, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFB90, 0xFFFFFD7FFFDFFB7C, SOV_DEFAULT) Err#11 EAGAIN write(3, "\f\0\0\0\0\b\0\0\f\0\0\0".., 16) = 16 ioctl(3, DP_POLL, 0x005036B0) = 1 read(12, " G E T / f i l e / 1 1".., 4095) = 51 write(3, "\f\0\0\0\0\b\0\0\f\0\0\0".., 32) = 32 ioctl(3, DP_POLL, 0x005036B0) = 1 write(12, " H T T P / 1 . 0 2 0 0".., 1736) = 1736 close(12) = 0 write(3, "\f\0\0\0\0\b\0\0", 8) = 8 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 0 ioctl(3, DP_POLL, 0x005036B0) = 1 I have 2 squid instances. Both are taking the same amount of connections, and both are connecting to the same exact pool of origins via a lb. 2344 root 13G 13G cpu1 0 0 4:03:10 25% squid/1 2096 root 13G 13G sleep 31 0 4:47:22 9.2% squid/1 After about 14 hours of runtime, the instances hit 25% utilization, and then never seem to restabilize. This is all I see in my cache.log for the instance that is maxed out: 2007/10/05 10:47:25| clientReadRequest: FD 107 (82.38.189.46:5430) Invalid Request 2007/10/05 11:05:13| WARNING: unparseable HTTP header field {Accept-CharsetGET /pict/320155568274_1.jpg HTTP/1.1} 2007/10/05 11:06:55| parseHttpRequest: Unsupported method 'Connection:' 2007/10/05 11:06:55| clientReadRequest: FD 1808 (84.71.71.234:35312) Invalid Request 2007/10/05 11:06:55| parseHttpRequest: Unsupported method 'Connection:' 2007/10/05 11:06:55| clientReadRequest: FD 1007 (12.25.108.29:63647) Invalid Request 2007/10/05 11:22:01| parseHttpRequest: Unsupported method 'Connection:' 2007/10/05 11:22:01| clientReadRequest: FD 1612 (81.104.41.63:48329) Invalid Request 2007/10/05 11:22:01| parseHttpRequest: Unsupported method 'Connection:' 2007/10/05 11:22:01| clientReadRequest: FD 1685 (74.236.38.154:50482) Invalid Request 2007/10/05 11:22:06| parseHttpRequest: Unsupported method 'Connection:' 2007/10/05 11:22:06| clientReadRequest: FD 6278 (83.112.151.249:53849) Invalid Request The box is a 2 cpu dual core, so each squid instance maxes out at 25% cpu. The are strictly in memory cache (no disk), and they each have 9G of RAM per instance. Can someone give me an idea of what is happening? Thanks. ** Greetings, Also, here is some truss output to show what the process is doing. accept(9, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) Err#11 EAGAIN write(5635, " G E T / f i l e / 2 7".., 842) = 842 write(5636, " G E T / f i l e / 2 5".., 654) = 654 write(5637, " G E T / f i l e / 2 3".., 475) = 475 write(5638, " H T T P / 1 . 0 2 0 0".., 3100) = 3100 read(5638, 0x35F4C4A00, 4095) Err#11 EAGAIN read(5641, " G E T / f i l e / 2 6".., 4095) = 468 write(5644, " H T T P / 1 . 0 2 0 0".., 2117) = 2117 read(5644, 0x30A678AB0, 4095) Err#11 EAGAIN write(5645, " H T T P / 1 . 0 2 0 0".., 3487) = 3487 read(5645, 0x3568248E0, 4095) Err#11 EAGAIN write(5646, " H T T P / 1 . 0 2 0 0".., 4130) = 4130 read(5647, " G E T / f i l e / 2 6".., 4095) = 383 write(5649, " G E T / f i l e / 2 8".., 500) = 500 read(5651, " G E T / f i l e / 1 3".., 4095) = 364 write(5652, " H T T P / 1 . 0 2 0 0".., 3331) = 3331 read(5652, 0x35BF4ACF0, 4095) Err#11 EAGAIN read(5653, 0x35A5B2B70, 4095) Err#131 ECONNRESET close(5653) = 0 read(5655, 0x35D087890, 4095) Err#131 ECONNRESET close(5655) = 0 write(5656, " H T T P / 1 . 0 2 0 0".., 2459) = 2459 read(5656, 0x358970130, 4095) Err#11 EAGAIN read(5657, 0x30E6DB710, 4095) = 0 close(5657) = 0 write(5663, " G E T / f i l e / 1 1".., 541) = 541 write(5666, " H T T P / 1 . 0 2 0 0".., 2539) = 2539 read(5666, 0x2490B2C20, 4095) Err#11 EAGAIN write(5669, " H T T P / 1 . 0 2 0 0".., 2783) = 2783 read(5669, 0x35A397400, 4095) Err#11 EAGAIN read(5670, " G E T / f i l e / 2 6".., 4095) = 477 read(5671, 0x1F6170000, 4095) Err#131 ECONNRESET close(5671) = 0 write(5672, " H T T P / 1 . 0 2 0 0".., 2031) = 2031 read(5672, 0x358112740, 4095) Err#11 EAGAIN write(5683, " G E T / f i l e / 1 1".., 463) = 463 read(5684, " G E T / f i l e / 1 9".., 4095) = 442 write(5685, " H T T P / 1 . 0 2 0 0".., 4127) = 4127 write(5686, " H T T P / 1 . 0 2 0 0".., 2882) = 2882 read(5686, 0x35CE62750, 4095) Err#11 EAGAIN read(5687, " G E T / f i l e / 2 0".., 4095) = 994 read(5691, " G E T / f i l e / 1 4".., 4095) = 375 write(5692, " H T T P / 1 . 0 2 0 0".., 2392) = 2392 read(5692, 0x35A3077F0, 4095) Err#11 EAGAIN read(5693, " G E T / f i l e / 1 6".., 4095) = 643 write(5702, " H T T P / 1 . 0 2 0 0".., 2435) = 2435 read(5702, 0x35C769C90, 4095) Err#11 EAGAIN accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3156 getsockname(3156, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3156, F_GETFL) = 130 fcntl(3156, F_SETFD, 0x00000083) = 0 fcntl(3156, F_GETFL) = 130 fcntl(3156, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3158 getsockname(3158, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3158, F_GETFL) = 130 fcntl(3158, F_SETFD, 0x00000083) = 0 fcntl(3158, F_GETFL) = 130 fcntl(3158, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3161 getsockname(3161, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3161, F_GETFL) = 130 fcntl(3161, F_SETFD, 0x00000083) = 0 fcntl(3161, F_GETFL) = 130 fcntl(3161, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3169 getsockname(3169, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3169, F_GETFL) = 130 fcntl(3169, F_SETFD, 0x00000083) = 0 fcntl(3169, F_GETFL) = 130 fcntl(3169, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3170 getsockname(3170, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3170, F_GETFL) = 130 fcntl(3170, F_SETFD, 0x00000083) = 0 fcntl(3170, F_GETFL) = 130 fcntl(3170, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3175 getsockname(3175, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3175, F_GETFL) = 130 fcntl(3175, F_SETFD, 0x00000083) = 0 fcntl(3175, F_GETFL) = 130 fcntl(3175, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3176 getsockname(3176, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3176, F_GETFL) = 130 fcntl(3176, F_SETFD, 0x00000083) = 0 fcntl(3176, F_GETFL) = 130 fcntl(3176, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3177 getsockname(3177, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3177, F_GETFL) = 130 fcntl(3177, F_SETFD, 0x00000083) = 0 fcntl(3177, F_GETFL) = 130 fcntl(3177, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3179 getsockname(3179, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3179, F_GETFL) = 130 fcntl(3179, F_SETFD, 0x00000083) = 0 fcntl(3179, F_GETFL) = 130 fcntl(3179, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(8, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 3180 getsockname(3180, 0xFFFFFD7FFFDFFAE0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) = 0 fcntl(3180, F_GETFL) = 130 fcntl(3180, F_SETFD, 0x00000083) = 0 fcntl(3180, F_GETFL) = 130 fcntl(3180, F_SETFL, FWRITE|FNONBLOCK) = 0 accept(9, 0xFFFFFD7FFFDFFAF0, 0xFFFFFD7FFFDFFADC, SOV_DEFAULT) Err#11 EAGAIN read(5703, " G E T / f i l e / 1 8".., 4095) = 607 write(5704, " H T T P / 1 . 0 2 0 0".., 2416) = 2416 read(5704, 0x2F9114E50, 4095) Err#11 EAGAIN read(5706, " G E T / f i l e / 1 6".., 4095) = 382 write(5707, " H T T P / 1 . 0 2 0 0".., 2493) = 2493 read(5707, 0x29D770F60, 4095) Err#11 EAGAIN write(5709, " H T T P / 1 . 0 2 0 0".., 2681) = 2681 read(5709, 0x35857DA50, 4095) Err#11 EAGAIN write(5717, " G E T / f i l e / 2 9".., 538) = 538 write(5718, " G E T / f i l e / 2 6".., 395) = 395 write(5720, " H T T P / 1 . 0 2 0 0".., 2765) = 2765 read(5720, 0x35882EC00, 4095) Err#11 EAGAIN write(5721, " H T T P / 1 . 0 2 0 0".., 2993) = 2993 read(5721, 0x3577FA750, 4095) Err#11 EAGAIN write(5722, " H T T P / 1 . 0 2 0 0".., 2167) = 2167 read(5722, 0x246BF64B0, 4095) Err#11 EAGAIN read(5723, 0x358E66F80, 4095) Err#131 ECONNRESET close(5723) = 0 write(5724, " H T T P / 1 . 0 2 0 0".., 1989) = 1989 read(5724, 0x35E2A5B40, 4095) Err#11 EAGAIN write(5725, " H T T P / 1 . 0 2 0 0".., 2038) = 2038 close(5725) = 0 read(5727, " G E T / f i l e / 3 3".., 4095) = 382 write(5733, " H T T P / 1 . 0 2 0 0".., 2905) = 2905 read(5733, 0x357CCA630, 4095) Err#11 EAGAIN write(5734, " H T T P / 1 . 0 2 0 0".., 3072) = 3072 read(5734, 0x35C535630, 4095) Err#11 EAGAIN write(5735, " H T T P / 1 . 0 2 0 0".., 3366) = 3366 **** On 10/5/07, Frank Ruiz <frank.ruiz@xxxxxxxxx> wrote: > I have 2 squid instances. > > Both are taking the same amount of connections, and both are > connecting to the same exact pool of origins via a lb. > > 2344 root 13G 13G cpu1 0 0 4:03:10 25% squid/1 > 2096 root 13G 13G sleep 31 0 4:47:22 9.2% squid/1 > > > After about 14 hours of runtime, the instances hit 25% utilization, > and then never seem to restabilize. > > > This is all I see in my cache.log for the instance that is maxed out: > > 2007/10/05 10:47:25| clientReadRequest: FD 107 (82.38.189.46:5430) > Invalid Request > 2007/10/05 11:05:13| WARNING: unparseable HTTP header field > {Accept-CharsetGET /pict/320155568274_1.jpg HTTP/1.1} > 2007/10/05 11:06:55| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:06:55| clientReadRequest: FD 1808 (84.71.71.234:35312) > Invalid Request > 2007/10/05 11:06:55| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:06:55| clientReadRequest: FD 1007 (12.25.108.29:63647) > Invalid Request > 2007/10/05 11:22:01| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:22:01| clientReadRequest: FD 1612 (81.104.41.63:48329) > Invalid Request > 2007/10/05 11:22:01| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:22:01| clientReadRequest: FD 1685 (74.236.38.154:50482) > Invalid Request > 2007/10/05 11:22:06| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:22:06| clientReadRequest: FD 6278 (83.112.151.249:53849) > Invalid Request > > > The box is a 2 cpu dual core, so each squid instance maxes out at 25% cpu. > The are strictly in memory cache (no disk), and they each have 9G of > RAM per instance. > > Can someone give me an idea of what is happening? > > Thanks. > Here are my compile time options: ./configure --enable-storeio=diskd,null --enable-snmp --enable-devpoll On 10/5/07, Frank Ruiz <frank.ruiz@xxxxxxxxx> wrote: - Show quoted text - > I have 2 squid instances. > > Both are taking the same amount of connections, and both are > connecting to the same exact pool of origins via a lb. > > 2344 root 13G 13G cpu1 0 0 4:03:10 25% squid/1 > 2096 root 13G 13G sleep 31 0 4:47:22 9.2% squid/1 > > > After about 14 hours of runtime, the instances hit 25% utilization, > and then never seem to restabilize. > > > This is all I see in my cache.log for the instance that is maxed out: > > 2007/10/05 10:47:25| clientReadRequest: FD 107 (82.38.189.46:5430) > Invalid Request > 2007/10/05 11:05:13| WARNING: unparseable HTTP header field > {Accept-CharsetGET /pict/320155568274_1.jpg HTTP/1.1} > 2007/10/05 11:06:55| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:06:55| clientReadRequest: FD 1808 (84.71.71.234:35312) > Invalid Request > 2007/10/05 11:06:55| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:06:55| clientReadRequest: FD 1007 (12.25.108.29:63647) > Invalid Request > 2007/10/05 11:22:01| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:22:01| clientReadRequest: FD 1612 (81.104.41.63:48329) > Invalid Request > 2007/10/05 11:22:01| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:22:01| clientReadRequest: FD 1685 (74.236.38.154:50482) > Invalid Request > 2007/10/05 11:22:06| parseHttpRequest: Unsupported method 'Connection:' > 2007/10/05 11:22:06| clientReadRequest: FD 6278 (83.112.151.249:53849) > Invalid Request > > > The box is a 2 cpu dual core, so each squid instance maxes out at 25% cpu. > The are strictly in memory cache (no disk), and they each have 9G of > RAM per instance. > > Can someone give me an idea of what is happening? > > Thanks. > Also, I have 32G additional RAM avail, and I swap looks healthy: 0 0 0 41870868 33463280 0 0 0 0 0 0 0 0 0 0 0 7381 13369 1557 36 6 58 0 0 0 41870868 33463280 0 0 0 0 0 0 0 2 0 0 0 7503 15598 1498 36 8 57 0 0 0 41870868 33463280 0 0 0 0 0 0 0 0 0 0 0 8071 15602 1662 35 7 58 0 0 0 41870868 33463280 0 0 0 0 0 0 0 3 0 0 0 8121 16271 1487 36 12 53 0 0 0 41870868 33463280 0 0 0 0 0 0 0 0 0 0 0 8154 15720 1545 36 7 57 0 0 0 41870868 33463280 0 0 0 0 0 0 0 0 0 0 0 8322 15764 1491 35 8 56 0 0 0 41870856 33463268 0 0 0 0 0 0 0 0 0 0 0 8386 19134 1863 34 8 58