NetBSD-Bugs archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

kern/43893: Hard lock under moderate filtering web-proxy use



>Number:         43893
>Category:       kern
>Synopsis:       Under moderate squid + dansguardian use, machines frequently 
>lock up (only responding to DDB)
>Confidential:   no
>Severity:       critical
>Priority:       high
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Wed Sep 22 08:25:00 +0000 2010
>Originator:     Stephen Borrill
>Release:        NetBSD 5.1_RC4
>Organization:
>Environment:
        
        
System: NetBSD proxy2 5.1_RC4 NetBSD 5.1_RC4 (NETMANRAIDDBG) #1: Mon Sep 20 
12:54:59 BST 2010  
root%builder.internal.precedence.co.uk@localhost:/usr/obj/5.0/i386/sys/arch/i386/compile/NETMANRAIDDBG
 i386
Architecture: i386
Machine: i386
>Description:
We use squid as a caching web-proxy with a number of ACLs with success. If 
however,
dansguardian (content-filtering) is set as an upstream proxy (with another 
non-caching instance of
squid upstream from dansguardian to act as a fetcher), then under moderate to 
heavy use (say 500
client machines), the server will lock solid a few times a day. There is no 
response at the console
nor on the network. However, with a serial console, it is possible to break 
into DDB.

This used to work reliably; we've changed a few components over the months and 
now it fails reliably.
Changes include:
- upgrade to squid 3.1.4 from 2.7.x
- upgrade from NetBSD 4 to NetBSD 5.0_STABLE and then up to RC4

Here's some data from DDB:
db{0}> machine cpu 0
using CPU 0
db{0}> bt
breakpoint(0,3f8,5,6,c572548c,d8146dc0,d8080eac,c447e00c,c447f000,7fb) at 
netbsd:breakpoint+0x4
comintr(d8146cb4,d8080ebc,6,10,30,c0b40010,d8080010,c0b4d880,1,d8080f4c) at 
netbsd:comintr+0x575
Xintr_ioapic_edge5() at netbsd:Xintr_ioapic_edge5+0xa9
--- interrupt ---
fatal page fault in supervisor mode
trap type 6 code 0 eip c05db07f cs 8 eflags 210206 cr2 3e ilevel 8
kernel: supervisor trap page fault, code=0
Faulted in DDB; continuing...
db{0}> machine cpu 1
using CPU 1
db{0}> bt
x86_pause(d5975ce4,d8096ccc,0,0,80,5,0,c04dbb0e,0,0) at netbsd:x86_pause
mutex_vector_enter(d5964f80,c04f98f2,0,d59737c0,c6001884,d809a000,d8096d40,c04f99cf,c60017fc,d59737c0)
 at netbsd:mutex_vector_enter+0x115
tcp_timer_2msl(c60017fc,d59737c0,7,d809a000,d808c074,d809a060,d809a868,d809b068,d809b868,c0167350)
 at netbsd:tcp_timer_2msl+0x1c
callout_softclock(0,10,30,10,10,0,6cc860,bfbf82c8,0,d8096da0) at 
netbsd:callout_softclock+0x25f
softint_dispatch(d596a020,2,0,0,0,0,d8096d90,d8096af4,d8096b10,0) at 
netbsd:softint_dispatch+0x9f
DDB lost frame for netbsd:Xsoftintr+0x3d, trying 0xd8096d88
Xsoftintr() at netbsd:Xsoftintr+0x3d
--- interrupt ---
fatal page fault in supervisor mode
trap type 6 code 0 eip c05db07f cs 8 eflags 210206 cr2 3a ilevel 8
kernel: supervisor trap page fault, code=0
Faulted in DDB; continuing...
db{0}> machine cpu 2
using CPU 2
db{0}> bt
tcp_output(c5830a04,c9e69c2e,0,d80c4c9c,2c,0,d80c4bcc,ff,0,0) at 
netbsd:tcp_output+0x81
tcp_input(c58c4500,14,6,1,d80c0010,d80c0010,d5975ce0,d80c0154,14,c58c4500) at 
netbsd:tcp_input+0x1fb4
ip_input(c58c4500,0,43b83278,0,0,d80c01ec,d80c4d80,c04ed8df,0,d96c0010) at 
netbsd:ip_input+0x6a1
ipintr(0,d96c0010,d80c0030,10,d80c0010,0,6cc360,d9723bac,0,d80c4da0) at 
netbsd:ipintr+0x4d
softint_dispatch(d96cc860,4,0,0,0,0,d80c4d90,d80c4bd8,d80c4c30,0) at 
netbsd:softint_dispatch+0x9f
DDB lost frame for netbsd:Xsoftintr+0x3d, trying 0xd80c4d88
Xsoftintr() at netbsd:Xsoftintr+0x3d
--- interrupt ---
fatal page fault in supervisor mode
trap type 6 code 0 eip c05db07f cs 8 eflags 210202 cr2 3c ilevel 8
kernel: supervisor trap page fault, code=0
Faulted in DDB; continuing...
db{0}> machine cpu 3
using CPU 3
db{0}> bt
mutex_vector_enter(d5964f80,c04f98f2,0,d5977800,c6001690,d8109000,d8105d40,c04f99cf,c6001608,d5977800)
 at netbsd:mutex_vector_enter+0x115
tcp_timer_2msl(c6001608,d5977800,7,d8109000,d80fb074,d8109060,d8109868,d810a068,d810a868,c0167350)
 at netbsd:tcp_timer_2msl+0x1c
callout_softclock(0,10,30,10,10,0,6cc360,d9723a7c,0,d8105da0) at 
netbsd:callout_softclock+0x25f
softint_dispatch(d9c5dd60,2,0,0,0,0,d8105d90,d8105af4,d8105b10,0) at 
netbsd:softint_dispatch+0x9f
DDB lost frame for netbsd:Xsoftintr+0x3d, trying 0xd8105d88
Xsoftintr() at netbsd:Xsoftintr+0x3d
--- interrupt ---
fatal page fault in supervisor mode
trap type 6 code 0 eip c05db07f cs 8 eflags 210206 cr2 3a ilevel 8
kernel: supervisor trap page fault, code=0
Faulted in DDB; continuing...

db{0}> ps
PID    LID S CPU     FLAGS       STRUCT LWP *               NAME WAIT
9923     1 3   2        84           db5e3080       dansguardian select
15735    1 3   1        84           db7abd20       dansguardian select
10305    1 3   2        84           db5e3580       dansguardian select
10183    1 3   0        84           d975c780       dansguardian select
8784     1 3   2        84           da895340       dansguardian select
8081     1 3   3        84           d9e0ed00       dansguardian select
12707    1 3   1        84           d9c5d5e0       dansguardian select
12186    1 3   1        84           da24a000       dansguardian select
11493    1 3   3        84           db3c22a0       dansguardian select
12795    1 3   0        84           db8a7ac0       dansguardian select
11907    1 3   2        84           db46dcc0       dansguardian select
8044     1 3   3        84           dba42360       dansguardian select
10736    1 3   1        84           daea1ae0       dansguardian select
9676     1 3   3        84           d9cd2500       dansguardian select
10750    1 3   2        84           da255540       dansguardian select
9439     1 3   2        84           dafc7a00       dansguardian select
12402    1 3   2        84           d988e2e0       dansguardian select
10077    1 3   0        84           da252a20       dansguardian select
5162     1 3   1        84           db8a7340       dansguardian select
7605     1 3   2        84           da895840       dansguardian select
10856    1 3   1        84           db7ab0a0       dansguardian select
10784    1 3   1        84           dba42860       dansguardian select
7386     1 3   1        84           da252020       dansguardian select
4788     1 3   1        84           d9cd2780       dansguardian select
10442    1 3   1        84           db8a7840       dansguardian select
8920     1 3   0        84           db7ab320       dansguardian select
10648    1 3   1        84           db503ce0       dansguardian select
9134     1 3   2        84           db503560       dansguardian select
5949     1 3   1        84           d9dcf060       dansguardian select
8298     1 3   0        84           db46d540       dansguardian select
9402     1 3   3        84           da890820       dansguardian select
3938     1 3   2        84           da8900a0       dansguardian select
12341    1 3   0        84           da2552c0       dansguardian select
6073     1 3   1        84           da895ac0       dansguardian select
10898    1 3   2        84           db46d2c0       dansguardian select
9492     1 3   1        84           d9c5d0e0       dansguardian select
8914     1 3   0        84           d9dcf2e0       dansguardian select
10890    1 3   3        84           db46d7c0       dansguardian select
12834    1 3   2        84           db5e3d00       dansguardian select
8605     1 3   1        84           d975c500       dansguardian select
9313     1 3   2        84           dba420e0       dansguardian select
9349     1 3   1        84           d9cd2c80       dansguardian select
2516     1 3   1        84           dafc7280       dansguardian select
5086     1 3   3        84           da24a500       dansguardian select
8956     1 3   2        84           db3c2ca0       dansguardian select
11927    1 3   3        84           db3c2a20       dansguardian select
7853     1 3   1        84           db3c27a0       dansguardian select
8917     1 3   3        84           da02f0c0       dansguardian select
11031    1 3   3        84           db503060       dansguardian select
9097     1 3   1        84           da2522a0       dansguardian select
8548     1 3   3        84           d9e0e800       dansguardian select
10123    1 3   2        84           da252520       dansguardian select
9224     1 3   0        84           db3c2020       dansguardian select
10488    1 3   0        84           dba425e0       dansguardian select
9520     1 3   2        84           d9834040       dansguardian select
7941     1 3   3        84           da034360       dansguardian select
4834     1 3   2        84           d9834a40       dansguardian select
6266     1 3   3        84           d98347c0       dansguardian select
6672     1 3   1        84           daea10e0       dansguardian select
4749     1 3   0        84           d9834540       dansguardian select
2885     1 3   3        84           d9c5d360       dansguardian select
9051     1 3   0        84           daea1d60       dansguardian select
1602     1 3   3        84           db3c2520              httpd semwait
2230     1 3   3        84           da02f5c0       dansguardian select
3763     1 3   3        84           da890d20       dansguardian select
1604     1 3   2        84           da2e02e0          checkuser netio
1708     1 3   3        84           d988ece0          checkuser netio
1818     1 3   0        84           da02f340          checkuser netio
1981     1 3   1        84           d9eb9820          checkuser netio
1596     1 3   2        84           da2e0560          checkuser netio
1982     1 3   3        84           d988e560          checkuser netio
1473     1 3   0        84           da24ac80          checkuser netio
1763     1 3   3        84           da02f840          checkuser netio
1656     1 3   1        84           d975ca00          checkuser netio
1313     1 3   1        84           da034d60          checkuser netio
2311     1 3   3        84           d98342c0        checkpasswd netio
1184     1 3   2        84           d988e7e0        checkpasswd netio
1942     1 3   2        84           d988e060        checkpasswd netio
1902     1 3   2        84           d97dd520        checkpasswd netio
1809     1 3   3        84           d91287e0        checkpasswd netio
2059     1 3   2        84           d988ea60          ntlm_auth netio
992      1 3   1        84           da0345e0          ntlm_auth netio
2035     1 3   0        84           d9eb9d20          ntlm_auth netio
1940     1 3   3        84           da408d00          ntlm_auth netio
2134     1 3   2        84           d97dd2a0          ntlm_auth netio
1672     1 3   2        84           d97ddca0          ntlm_auth netio
1993     1 3   1        84           da0340e0          ntlm_auth netio
1554     1 3   0        84           da034860          ntlm_auth netio
2099     1 3   2        84           d97dda20          ntlm_auth netio
3228     1 3   1        84           d97dd020          ntlm_auth netio
667      1 3   1        84           da02fac0       dansguardian select
807      1 3   1        84           d9eb9320       dansguardian select
656  >   1 7   3         4           d9c5dd60       dansguardian
1034     1 3   2        84           d9e0e080               tcsh ttyraw
450      1 3   3        84           d9cd2000                 sh wait
891      1 3   3        84           d8fcd540               tcsh pause
566      1 3   2        84           d9e0e300               sshd select
625      1 3   3        84           d9dcf560              httpd semwait
751      1 3   3        84           d9dcf7e0              httpd semwait
749      1 3   3        84           d9dcfa60              httpd semwait
553      1 3   3        84           d9dcfce0              httpd kqueue
747      1 3   3        84           d9d80040              httpd semwait
682      1 3   2        84           d9d802c0              httpd socket
871      1 3   3        84           d9d80540              getty ttyraw
486      1 3   2        84           d9d807c0              getty ttyraw
549      1 3   3        84           d9d80a40              getty ttyraw
548      1 3   0        84           d8fcd7c0              getty ttyraw
542      1 3   0        84           d9b7c840              httpd select
858      1 3   2        84           d9c5d860            chronyd select
787      1 3   1        84           d9b7c0c0               cron nanoslp
709     10 3   0        84           d9d80cc0             mysqld sigwait
               9 3   1        84           d9d11020             mysqld parked
               8 3   1        84           d9d112a0             mysqld select
               7 3   2        84           d9d11520             mysqld select
               5 3   3        84           d9d117a0             mysqld parked
               4 3   3        84           d9d11a20             mysqld parked
               3 3   0        84           d9d11ca0             mysqld parked
               2 3   0        84           d9cd2280             mysqld parked
               1 3   0        84           d99f0a80             mysqld select
857      1 3   2        84           d9b7cac0                 sh wait
525      1 3   3        84           d9b7c5c0         rpc.pcnfsd select
192      1 3   3        84           d9b7cd40              rsync select
567      1 3   2        84           d9b63320               smbd select
595      1 3   3        84           d9b635a0             smartd nanoslp
564      1 3   0        84           d9b63aa0           winbindd select
571      1 3   2        84           d9b63d20           winbindd select
583      1 3   0        84           d99f0080              httpd semwait
287      1 3   1        84           d99f0d00              httpd kqueue
476      1 3   2        84           d99f0300               smbd select
536      1 3   0        84           d99f0580               nmbd select
558      1 3   3        84           d99f0800           sendmail pause
490      1 3   1        84           d9551340            unlinkd piperd
501      1 3   3        84           d9128a60           sendmail select
398  >   1 7   2         4           d96cc860              squid
380      1 3   0        84           d975cc80              squid wait
405      1 3   0        84           d96cc0e0            unlinkd piperd
396      1 3   2        84           d95515c0              httpd socket
374      1 3   0        84           d96cc360              squid select
361      1 3   1        84           d9551840              squid wait
357      1 3   0        84           d96cc5e0               sshd select
343      2 3   2        84           d9b7c340      in.imapproxyd nanoslp
               1 3   2        84           d96ccd60      in.imapproxyd socket
338      1 3   3        84           d96ccae0              inetd kqueue
335      1 3   1        84           d95510c0              httpd select
340      1 3   3        84           d949f820           winbindd select
331      1 3   3        84           d9551ac0           winbindd select
305      1 3   0        84           d9128560                lpd select
260      5 3   3        84           d9551d40              slave nfsd
               4 3   1        84           d949f0a0              slave nfsd
               3 3   1        84           d949f320              slave nfsd
               2 3   2        84           d949f5a0              slave nfsd
               1 3   2        84           d949faa0             master select
250      1 3   2        84           d949fd20             mountd select
200      1 3   2        84           d948c080            rpcbind select
191      7 3   1        84           d948c300              named select
               6 3   2        84           d948c580              named parked
               5 3   0        84           d948c800              named parked
               4 3   1        84           d948ca80              named parked
               3 3   2        84           d948cd00              named parked
               2 3   0        84           d9128060              named parked
               1 3   0        84           d91282e0              named sigwait
166      1 2   2         4           d8fcd2c0            syslogd
1        1 3   0        84           d597b340               init wait
0       72 3   2       204           d9128ce0            physiod physiod
              71 3   3       204           d8fcda40        vmem_rehash vmem_reha
sh
              70 3   1       204           d8fcdcc0           aiodoned aiodoned
              69 3   1       204           d8fca020            ioflush syncer
              68 3   1       204           d597cae0           pgdaemon pgdaemon
              67 3   3       204           d8fca2a0            raidio2 raidiow
              66 3   1       204           d8fca520              raid2 rfwcond
              65 3   0       204           d8fca7a0            raidio1 raidiow
              64 3   0       204           d8fcaa20              raid1 rfwcond
              63 3   3       204           d8fcaca0            raidio0 raidiow
              62 3   1       204           d8fc6000              raid0 rfwcond
              61 3   3       204           d8fc6280          cryptoret crypto_wa
it
              60 3   0       204           d597b840              ipmi0 ipmi0
              59 3   0       204           d597b0c0               ipmi ipmi_poll

              58 3   1       204           d8fc6500          atapibus0 sccomp
              56 3   0       204           d597bac0               usb2 usbevt
              55 3   0       204           d597bd40               usb1 usbevt
              54 3   3       204           d597b5c0               usb0 usbevt
              53 3   1       204           d8fc6780         usbtask-dr usbtsk
              52 3   1       204           d8fc6a00         usbtask-hc usbtsk
              51 3   3       204           d8fc6c80               usb3 usbevt
              50 3   1       204           d597cd60              unpgc unpgc
              49 3   2       204           d597c0e0          coretemp3 coretemp3

              48 3   1       204           d597c360          coretemp2 coretemp2

              47 3   2       204           d597c5e0          coretemp1 coretemp1

              46 3   3       204           d597c860          coretemp0 coretemp0

              37 3   1       204           d59790a0            atabus3 atath
              36 3   3       204           d5979320            atabus2 atath
              35 3   0       204           d59795a0               iic0 iicintr
              34 3   0       204           d5979820            atabus1 atath
              33 3   1       204           d5979aa0            atabus0 atath
              32 3   0       204           d5979d20           scsibus0 sccomp
              31 3   3       204           d5977080               apm0 apmev
              30 3   3       204           d5977300            xcall/3 xcall
              29 1   3       204           d5977580          softser/3
           >  28 7   3       204           d5977800          softclk/3
              27 1   3       204           d5977a80          softbio/3
              26 1   3       204           d5977d00          softnet/3
              25 1   3       205           d5975060             idle/3
              24 3   2       204           d59752e0            xcall/2 xcall
              23 1   2       204           d5975560          softser/2
              22 1   2       204           d59757e0          softclk/2
              21 1   2       204           d5975a60          softbio/2
           >  20 7   2       204           d5975ce0          softnet/2
              19 1   2       205           d5973040             idle/2
              18 3   1       204           d59732c0            xcall/1 xcall
              17 1   1       204           d5973540          softser/1
           >  16 7   1       204           d59737c0          softclk/1
              15 1   1       204           d5973a40          softbio/1
              14 1   1       204           d5973cc0          softnet/1
           >  13 7   1       205           d596a020             idle/1
              12 3   0       204           d596a2a0             sysmon smtaskq
              11 3   0       204           d596a520           pmfevent pmfevent
              10 3   0       204           d596a7a0           nfssilly nfssilly
               9 3   2       204           d596aa20            cachegc cachegc
               8 3   1       204           d596aca0              vrele vrele
               7 3   0       204           d5967000            xcall/0 xcall
               6 1   0       204           d5967280          softser/0
           >   5 7   0       204           d5967500          softclk/0
               4 1   0       204           d5967780          softbio/0
               3 1   0       204           d5967a00          softnet/0
           >   2 7   0       205           d5967c80             idle/0
               1 3   0       204           c0b4a8e0            swapper schedule

db{0}> machine cpu 0
using CPU 0
db{0}> show lock
lock address : 000000000000000000 type     :               spin
initialized  : 0x00000000c053d846 interlock: 000000000000000000
db{0}> machine cpu 1
using CPU 1
db{0}> show lock
Sorry, no record of a lock with address 0x1 found.
db{0}> machine cpu 2
using CPU 2
db{0}> show lock
Sorry, no record of a lock with address 0x2 found.
db{0}> machine cpu 3
using CPU 3
db{0}> show lock
Sorry, no record of a lock with address 0x3 found.
db{0}> reboot 0x104

dumping to dev 18,8 offset 18657439
dump 158 157 156 155 154 153 152 151 150 149 148 147 146 145 144 143 142 141
140 139 138 137 136 135 134 133 132 131 130 129 128 127 126 125 124 123 122
121 120 119 118 117 116 115 114 113 112 111 110 109 108 107 106 105 104 103
102 101 100 99 98 97 96 95 94 93 92 91 90 89 88 87 86 85 84 83 82 81 80 79
78 77 76 75 74 73 72 71 70 69 68 67 66 65 64 63 62 61 60 59 58 57 56 55 54
53 52 51 50 49 48 47 46 45 44 43 42 41 40 39 38 37 36 35 34 33 32 31 30 29
28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1
succeeded


Mutex error: lockdebug_wantlock: acquiring sleep lock from interrupt context

lock address : 0x00000000c0c1274c type     :     sleep/adaptive
initialized  : 0x00000000c04feb96
shared holds :                  0 exclusive:                  0
shares wanted:                  0 exclusive:                  0
current cpu  :                  0 last held:                  3
current lwp  : 0x00000000d5967500 last held: 000000000000000000
last locked  : 0x00000000c04fea37 unlocked : 0x00000000c04feab7
owner field  : 000000000000000000 wait/spin:                0/0

Turnstile chain at 0xc0c12460.
=> No active turnstile for this lock.

panic: LOCKDEBUG
fatal breakpoint trap in supervisor mode
trap type 1 code 0 eip c05d8bfc cs 8 eflags 200246 cr2 3a ilevel 8
Stopped in pid 0.5 (system) at  netbsd:breakpoint+0x4:  popl    %ebp

>How-To-Repeat:
Install www/squid31 and www/dansguardian.
Configure two instances of squid. The first should be non-caching and listen 
only on localhost; a
configuration file is here:
pid_filename /var/run/squid-nc.pid
http_port 127.0.0.1:8123
icp_port 0
no_cache deny all
cache_access_log none
cache_store_log none
cache_log /usr/local/squid/logs/nocache.log
cache_effective_user nobody
cache_effective_group wheel
logfile_rotate 0
acl localhost src 127.0.0.0/8
http_access allow localhost
http_access deny all
cache_mgr nocache
cache_dir ufs /usr/local/squid/nocache 10MB 1 1 no-store
never_direct allow all

The second should be a standard squid configuration including the following 
lines:
cache_peer localhost parent 8124 0 no-query default name=localhost:8124
cache_peer_access localhost:8124 allow all
never_direct allow all
http_port 3128

Dansguardian should be set up with /usr/pkg/etc/dansguardian/dansguardian.conf 
including the
following:
filterip =127.0.0.1
filterport = 8124
proxyip = 127.0.0.1
proxyport = 8123

All three should be started and then browse using port 3128, which will forward 
to 8124
(dansguardian), which will forward to 8123 (non-caching squid) which will then 
fetch the pages from
the origin.
>Fix:
Only workaround is to not use dansguardian.

>Unformatted:
        
        


Home | Main Index | Thread Index | Old Index