Bug 709205 - bind 9.7.4 chews 100% CPU
bind 9.7.4 chews 100% CPU
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: bind (Show other bugs)
18
All Linux
unspecified Severity high
: ---
: ---
Assigned To: Tomas Hozza
Fedora Extras Quality Assurance
:
: 710315 739059 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2011-05-31 00:39 EDT by Ian Donaldson
Modified: 2014-05-09 16:00 EDT (History)
33 users (show)

See Also:
Fixed In Version: dhcp-4.2.5-2.fc17
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-06-17 21:28:28 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)
named.conf (957 bytes, text/plain)
2011-06-01 07:28 EDT, Ian Donaldson
no flags Details
named.conf (3.56 KB, text/plain)
2011-12-30 17:18 EST, Rich Rauenzahn
no flags Details

  None (edit)
Description Ian Donaldson 2011-05-31 00:39:22 EDT
Description of problem:

Just upgraded to bind-9.7.4-0.1.b1.fc14.i686 and now named chews 100% CPU
all the time.

Version-Release number of selected component (if applicable):


bind-9.7.4-0.1.b1.fc14.i686

How reproducible:

100%


Steps to Reproduce:
1.  /etc/init.d/bind start
2.
3.
  
Actual results:



top
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND   
 6580 named     20   0 42928  10m 2224 S 97.3  2.1   8:27.28 named      
 
top -H 
 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND   
 6582 named     20   0 42928  10m 2224 S 49.1  2.1   6:29.20 named      
 6581 named     20   0 42928  10m 2224 R 48.8  2.1   6:29.40 named      
 6583 named     20   0 42928  10m 2224 S  0.3  2.1   0:00.06 named      


Nothing interesting in syslogs.


Expected results:

should be idle


Additional info:

selinux is enabled in targeted mode



strace/pstack output

# ps -fu named
UID        PID  PPID  C STIME TTY          TIME CMD
named     6580     1 94 04:23 ?        00:10:22 /usr/sbin/named -u named

# strace -f -p 6580
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 93737}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 93890832}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268233, {23, 178861168} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 94047}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 94153}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 94227}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 94720}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 94873447}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268235, {23, 177878553} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 95028}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 95098}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 95573}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 95730272}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268237, {23, 177021728} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 95889}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 95960}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 96032}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 96346}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 96654563}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268239, {23, 176097437} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 96815}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 96888}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 97205}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 97350748}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268241, {23, 175401252} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 97669}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 97742}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 97814}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 98131}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 98279207}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268243, {23, 174472793} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 98601}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 98678}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 98994}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 99142090}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268245, {23, 173609910} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 99296}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 99367}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 99642}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 99966}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 100113927}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268247, {23, 172638073} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 100269}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 100341}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 100822}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 100974356}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268249, {23, 171777644} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 101165}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 101240}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 101312}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 101806}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 101958672}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268251, {23, 170793328} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 102117}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 102190}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 102664}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 102817647}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268253, {23, 169934353} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 102970}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 103041}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 103114}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 103593}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 103746661}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268255, {23, 169005339} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 103902}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 103974}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 104284}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 104584775}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268257, {23, 168167225} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 104749}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 104860}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 104933}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 105252}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 105548104}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268259, {23, 167203896} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 105730}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 105803}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 106118}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 106265708}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268261, {23, 166486292} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 106621}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 106698}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 106772}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 107093}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 107242133}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268263, {23, 165509867} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 107416}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 107632}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 107953}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 108101465}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268265, {23, 164650535} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 108293}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 108363}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 108600}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 108924}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 109071375}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268267, {23, 163680625} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 109226}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 109299}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 109776}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 109925266}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268269, {23, 162826734} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 110083}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 110153}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 110225}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 110740}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 110892220}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268271, {23, 161859780} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 111047}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 111120}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 111601}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 111750455}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268273, {23, 161001545} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 111905}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 111976}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 112050}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 112548}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 112715961}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268275, {23, 160036039} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 112874}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 112945}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 113256}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 113543079}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268277, {23, 159208921} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 113721}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 113792}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 113864}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 114214}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 114363931}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268279, {23, 158388069} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 114691}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 114765}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 115082}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 115227701}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268281, {23, 157524299} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 115384}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 115620}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 115693}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 116011}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 116195305}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268283, {23, 156556695} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 116352}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 116579}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 116905}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 117052087}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268285, {23, 155699913} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 117209}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 117281}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 117353}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 117829}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 117981634}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268287, {23, 154770366} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 118165}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 118241}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 118735}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 118885293}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268289, {23, 153866707} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 119041}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 119113}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 119185}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 119661}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 119812509}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268291, {23, 152939491} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 119968}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 120039}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 120404}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 120712918}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268293, {23, 152039082} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 120870}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 120943}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 121015}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 121330}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 121625803}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268295, {23, 151126197} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 121787}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 121860}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 122208}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 122356522}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268297, {23, 150395478} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 122691}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 122763}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 122836}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 123152}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 123300030}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268299, {23, 149451970} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 123614}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 123690}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 124010}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 124193546}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268301, {23, 148558454} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 124354}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 124586}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 124664}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 124987}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 125136329}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268303, {23, 147615671} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 125293}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 125363}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 125844}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 125995329}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268305, {23, 146756671} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 126188}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 126260}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 126333}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 126811}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 126962243}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268307, {23, 145789757} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 127116}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 127188}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 127664}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 127814097}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268309, {23, 144937903} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 127972}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 128044}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 128114}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 128592}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 128782327}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268311, {23, 143969673} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 128939}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 129012}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 129327}, NULL) = 0
[pid  6582] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1) = 0
[pid  6582] clock_gettime(CLOCK_REALTIME, {1306816366, 129726121}) = 0
[pid  6582] futex(0xb770c04c, FUTEX_WAIT_PRIVATE, 31268313, {23, 143025879} <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] gettimeofday({1306816366, 129889}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 129960}, NULL) = 0
[pid  6581] gettimeofday({1306816366, 130033}, NULL) = 0
[pid  6581] futex(0xb770c04c, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb770c048, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] futex(0xb770c018, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid  6581] <... futex resumed> )       = 1
[pid  6581] futex(0xb770c018, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  6582] <... futex resumed> )       = 0
[pid  6582] gettimeofday({1306816366, 130353}, NULL) = 0
^CProcess 6580 detached
Process 6581 detached
Process 6582 detached
Process 6583 detached
# 

# pstack 6580
Thread 4 (Thread 0xb7705b70 (LWP 6581)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00b2239b in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x001677e9 in ?? () from /usr/lib/libisc.so.62
#3  0x00b1de99 in start_thread () from /lib/libpthread.so.0
#4  0x00cb9d2e in clone () from /lib/libc.so.6
Thread 3 (Thread 0xb6f04b70 (LWP 6582)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00b22743 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x001809d6 in isc_condition_waituntil () from /usr/lib/libisc.so.62
#3  0x0016a9b1 in ?? () from /usr/lib/libisc.so.62
#4  0x00b1de99 in start_thread () from /lib/libpthread.so.0
#5  0x00cb9d2e in clone () from /lib/libc.so.6
Thread 2 (Thread 0xb6703b70 (LWP 6583)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00cba516 in epoll_wait () from /lib/libc.so.6
#2  0x0017b371 in ?? () from /usr/lib/libisc.so.62
#3  0x00b1de99 in start_thread () from /lib/libpthread.so.0
#4  0x00cb9d2e in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7747950 (LWP 6580)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00c0d6ae in sigsuspend () from /lib/libc.so.6
#2  0x0016c90c in isc__app_ctxrun () from /usr/lib/libisc.so.62
#3  0x0016cd91 in isc__app_run () from /usr/lib/libisc.so.62
#4  0x00b5c731 in main ()



and again...

# pstack 6580
Thread 4 (Thread 0xb7705b70 (LWP 6581)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00b2239b in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x001677e9 in ?? () from /usr/lib/libisc.so.62
#3  0x00b1de99 in start_thread () from /lib/libpthread.so.0
#4  0x00cb9d2e in clone () from /lib/libc.so.6
Thread 3 (Thread 0xb6f04b70 (LWP 6582)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00b22743 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x001809d6 in isc_condition_waituntil () from /usr/lib/libisc.so.62
#3  0x0016a9b1 in ?? () from /usr/lib/libisc.so.62
#4  0x00b1de99 in start_thread () from /lib/libpthread.so.0
#5  0x00cb9d2e in clone () from /lib/libc.so.6
Thread 2 (Thread 0xb6703b70 (LWP 6583)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00cba516 in epoll_wait () from /lib/libc.so.6
#2  0x0017b371 in ?? () from /usr/lib/libisc.so.62
#3  0x00b1de99 in start_thread () from /lib/libpthread.so.0
#4  0x00cb9d2e in clone () from /lib/libc.so.6
Thread 1 (Thread 0xb7747950 (LWP 6580)):
#0  0x004ff416 in __kernel_vsyscall ()
#1  0x00c0d6ae in sigsuspend () from /lib/libc.so.6
#2  0x0016c90c in isc__app_ctxrun () from /usr/lib/libisc.so.62
#3  0x0016cd91 in isc__app_run () from /usr/lib/libisc.so.62
#4  0x00b5c731 in main ()
Comment 1 Ian Donaldson 2011-05-31 00:41:33 EDT
I should add that named *is* returning answers ok to queries, 
and recursion and zone transfers is only enabled for restricted hosts.
Comment 2 Ian Donaldson 2011-05-31 01:01:50 EDT
Backing out to previous version...

# ls bind*
bind-9.7.3-1.fc14.i686.rpm       bind-utils-9.7.3-1.fc14.i686.rpm
bind-libs-9.7.3-1.fc14.i686.rpm

# rpm -Uvh --oldpackage bind*
 ...

and now named doesn't show in top anymore
Comment 3 Adam Tkac 2011-06-01 07:15:43 EDT
I'm not able to reproduce this issue, named on my machine works fine (i.e. CPU utilization is same with both versions). Can you please attach your named.conf? Please strip all private data.
Comment 4 Ian Donaldson 2011-06-01 07:27:23 EDT
attached is named.conf minus private data.  Original has 73 zones; 72 slaves,
1 master.
Comment 5 Ian Donaldson 2011-06-01 07:28:42 EDT
Created attachment 502226 [details]
named.conf
Comment 6 Adam Tkac 2011-06-02 05:03:43 EDT
Unfortunately I'm still unable to reproduce this issue. Does named consume 100% CPU immediately when it is started?

Can you run named following way, please (as root)?

$ strace -f -s 1024 -o stracelog named -gunamed -d99 > log 2>&1

When named starts to consume 100% CPU, simply terminate it and attach the "log" and "stracelog" files here (you can bzip2 them if they are too big). Thank you in advance.
Comment 7 Ian Donaldson 2011-06-02 08:43:54 EDT
I've set up this FC14 9.7.4 bind on another (x86_64) FC14 server and tried to reproduce it.  

Started with the stock named.conf; no problem.  Then progressively
put in bits of my production named.conf.

It was all happy until I commented out this line, when named started
going nuts at startup (without any requests even being sent to it)

           managed-keys-directory "/var/named/dynamic";

my production named.conf doesn't have this line.

I've confirmed that the stock named.conf from
 
   bind-9.7.4-0.1.b1.fc14.x86_64

with the above line commented will produce the problem every time.
Comment 8 Panu Matilainen 2011-06-02 09:57:37 EDT
I can confirm the above: without the managed-keys-directory setting (which my configuration didn't have), bind-9.7.4-0.1.b1.fc14.x86_64 goes crazy eating cpu cycles like there's no tomorrow. Adding that line makes things normal again.
Comment 9 Adam Tkac 2011-06-02 10:48:22 EDT
Ah, that was the trick, removal of the managed-keys-directory directive triggers this bug. Let me check what happens.
Comment 10 Adam Tkac 2011-06-08 05:03:11 EDT
*** Bug 710315 has been marked as a duplicate of this bug. ***
Comment 11 Jan "Yenya" Kasprzak 2011-06-13 15:36:42 EDT
Me too. The "managed-keys-directory" directive mentioned in comment #7 did not help for me. In my /var/log/messages, there is the following message:

Jun 13 21:32:14 thorin setroubleshoot: SELinux is preventing /usr/sbin/named fro
m write access on the directory /var/named/chroot/var/named. For complete SELinu
x messages. run sealert -l 75f9b442-f638-4f28-9d82-747a09131e2c

After running

setenforce 0; /etc/init.d/named restart; setenforce 1

my bind no longer eats 100 % of CPU.
Comment 12 Adam Tkac 2011-09-16 09:15:02 EDT
*** Bug 739059 has been marked as a duplicate of this bug. ***
Comment 13 Ruth Ivimey-Cook 2011-09-16 09:20:47 EDT
Adding managed-keys-directory to my conf did make it work properly again for me.

Ruth
Comment 14 john.haxby@oracle.com 2011-09-16 12:47:46 EDT
For what it's worth, I have exactly the same issue and exactly the same fix as Ruth in comment #13, but with bind-9.8.1-1.fc15.x86_64
Comment 15 Adam Tkac 2011-09-19 04:57:35 EDT
Yeah, both 9.8.1 and 9.7.4 are bad. I reported this issue to upstream but I haven't received any response, yet...
Comment 16 George Machitidze 2011-10-17 17:11:53 EDT
Same with FC15
bind-9.8.1-1.fc15.x86_64

managed-keys-directory option + dir creation solved the problem - thanks for posting

I've run named in debug mode + run strace

I remember I saw something related to writing of jnl files that are now thrown into specified directory

SELinux disabled
DNSSEC disabled
zone transfer disabled
recursion disabled
notify disabled
Comment 17 Bill McGonigle 2011-11-10 22:00:23 EST
I hit this on f15 also, while setting up DNSSEC for my recursive resolver and the workaround fixed it.

This has something to do with dnssec keys, because this happened to me when I added:

  include "/etc/named.root.key";

which contains:

  managed-keys {
        # DNSKEY for the root zone.
        # Updates are published on root-dnssec-announce@icann.org
        . initial-key 257 3 8 "AwEAAagAIKlVZrpC6Ia7gEzahOR+9W29euxhJhVVLOyQbSEW0O8gcCjF FVQUTf6v58fLjwBd0YI0EzrAcQqBGCzh/RStIoO8g0NfnfL2MTJRkxoX bfDaUeVPQuYEhg37NZWAJQ9VnMVDxP/VHL496M/QZxkjf5/Efucp2gaD X6RS6CXpoY68LsvPVjR0ZSwzz1apAzvN9dlzEheX7ICJBBtuA6G3LQpz W5hOA2hzCTMjJPJ8LbqF6dsV6DoBQzgul0sGIcGOYl7OyQdXfZ57relS Qageu+ipAdTTJ25AsRTAoub8ONGcLmqrAmRLKBP1dfwhYB4N7knNnulq QxA+Uk1ihz0=";
};

That include might exist by default now, I dunno, this is an upgraded server.  So, managed-keys without managed-keys-directory is the killer.

What's surprising is that /var/named/dynamic exists outside of the chroot jail and its equivalent inside the jail doesn't exist.  Even though adding the workaround stopped the CPU burn, there are no files at all in the directory.

SELinux is disabled on this machine.
Comment 18 Deron Meranda 2011-11-20 01:50:43 EST
This is still an issue in Fedora 16 with bind-9.8.1-4.P1.fc16.x86_64

Is it possible to update the bug report to include Fedora version 14, 15, and 16.  That would make it a lot easier to find, as it is still unresolved.


If it helps, the low-level debugging output from named when it is in this infinite loop state looks like this:

20-Nov-2011 01:35:18.439 general: debug 1: zone_maintenance: managed-keys-zone ./IN: enter
20-Nov-2011 01:35:18.439 general: debug 1: zone_settimer: managed-keys-zone ./IN: enter
20-Nov-2011 01:35:18.439 general: debug 1: zone_timer: managed-keys-zone ./IN: enter
20-Nov-2011 01:35:18.439 general: debug 1: zone_maintenance: managed-keys-zone ./IN: enter

....repeat indefinitely...
Comment 19 Matěj Cepl 2011-11-20 14:43:34 EST
Changing the product version per comment 18.
Comment 20 Rich Rauenzahn 2011-12-30 17:17:12 EST
I'm also having this issue still with FC16 (32bit for what it's worth), first saw it with FC14.  I compiled my own bind-9.8.0-3.P1.fc15.i686.rpm to work around it on fc14.

I'll attach my named.conf as well -- I went ahead and added         

managed-keys-directory "/var/named/dynamic";

and it made no difference.
Comment 21 Rich Rauenzahn 2011-12-30 17:18:11 EST
Created attachment 550096 [details]
named.conf
Comment 22 Rich Rauenzahn 2011-12-30 17:33:22 EST
Not sure this helps at all, but, here's a stack trace:

Thread 5 (Thread 0xb777ab40 (LWP 8250)):
#0  0x002af416 in __kernel_vsyscall ()
#1  0x00ced4c2 in __lll_lock_wait () from /lib/libpthread.so.0
#2  0x00ce8e53 in _L_lock_693 () from /lib/libpthread.so.0
#3  0x00ce8c98 in pthread_mutex_lock () from /lib/libpthread.so.0
#4  0x002608bc in isc__timer_reset () from /usr/lib/libisc.so.83
#5  0x0073359a in ?? () from /usr/lib/libdns.so.81
#6  0x007539b9 in ?? () from /usr/lib/libdns.so.81
#7  0x0025d204 in ?? () from /usr/lib/libisc.so.83
#8  0x00ce6cd3 in start_thread () from /lib/libpthread.so.0
#9  0x010377ce in clone () from /lib/libc.so.6

Thread 4 (Thread 0xb6f79b40 (LWP 8251)):
#0  0x002af416 in __kernel_vsyscall ()
#1  0x00cea84c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x0025d0d9 in ?? () from /usr/lib/libisc.so.83
#3  0x00ce6cd3 in start_thread () from /lib/libpthread.so.0
#4  0x010377ce in clone () from /lib/libc.so.6

Thread 3 (Thread 0xb6778b40 (LWP 8252)):
#0  0x002af416 in __kernel_vsyscall ()
#1  0x00ced582 in __lll_unlock_wake () from /lib/libpthread.so.0
#2  0x00ce9cd7 in _L_unlock_622 () from /lib/libpthread.so.0
#3  0x00ce9c1a in __pthread_mutex_unlock_usercnt () from /lib/libpthread.so.0
#4  0x0025c43a in ?? () from /usr/lib/libisc.so.83
#5  0x0025fa14 in ?? () from /usr/lib/libisc.so.83
#6  0x00ce6cd3 in start_thread () from /lib/libpthread.so.0
#7  0x010377ce in clone () from /lib/libc.so.6

Thread 2 (Thread 0xb5f77b40 (LWP 8253)):
#0  0x002af416 in __kernel_vsyscall ()
#1  0x010381d6 in epoll_wait () from /lib/libc.so.6
#2  0x002707f1 in ?? () from /usr/lib/libisc.so.83
#3  0x00ce6cd3 in start_thread () from /lib/libpthread.so.0
#4  0x010377ce in clone () from /lib/libc.so.6

Thread 1 (Thread 0xb77bc980 (LWP 8249)):
#0  0x002af416 in __kernel_vsyscall ()
#1  0x00f74d82 in sigsuspend () from /lib/libc.so.6
#2  0x00261aa4 in isc__app_ctxrun () from /usr/lib/libisc.so.83
#3  0x00261ffe in isc__app_run () from /usr/lib/libisc.so.83
#4  0x003eee43 in main ()
Comment 23 Rich Rauenzahn 2011-12-30 19:26:47 EST
Well, on my system, I fixed this (so far) by making this file:

-rw-r--r-- 1 named named 0 Dec 30 16:20 /var/named/chroot/var/named/dynamic/managed-keys.bind

I saw an error about it in a log file with debug turned up to 20..

           channel simple_log {
                 severity debug 20;
                 print-category yes;
                 print-severity yes;
                 print-time     yes;
                 file "/var/log/named/tmp.log";
            };


            category default { simple_log; };

I also had one here:

# ll /var/named/dynamic/managed-keys.bind
-rw-r--r--. 1 named named 708 Dec  7  2010 /var/named/dynamic/managed-keys.bind

but since my environment is chroot'ed, it is in the wrong place...

Maybe the rpm needs to drop down a null length file in the chroot?
Comment 24 JesUs Lima 2012-01-17 20:36:57 EST
I have the same problem of hi cpu usage by named, solved this way:

mkdir /var/named/chroot/var/named/dynamic
chown named:named /var/named/chroot/var/named/dynamic
Comment 25 dobs 2012-05-24 16:22:55 EDT
+1
Have big LA...

http://savepic.su/2012809.png

-sh-4.2$ uname -a
Linux *.net 2.6.41.4-1.fc15.i686.PAE #1 SMP Tue Nov 29 11:47:02 UTC 2011 i686 i686 i386 GNU/Linux
-sh-4.2$ cat /etc/issue
Fedora release 15 (Lovelock)
Comment 26 dobs 2012-05-24 16:33:35 EDT
Adding line in named.conf
managed-keys-directory "/var/named/dynamic";
Fixed, Thanks!
Comment 27 Dagan McGregor 2012-06-12 06:16:55 EDT
 I just ran into this bug in Fedora 17, so it appears nobody has fixed this, what seems to be a race condition or something driving the CPU crazy.

 I am running bind-chroot.x86_64 32:9.9.1-2.P1.fc17 

 I had named-chroot.service running, it immediately went to 137% CPU. The config was valid with the named-checkconf and the local zone was valid with named-checkzone.

 However, the directories under /var/named/chroot/var/named were all owned by root:named instead of named:named. This caused named service to run 130% CPU in 'top' but was not actually stopping it from running and returning results.

 It was a simple change required:

 # chown -R named: /var/named/chroot/var/named/{data,dynamic,slaves}
 
 This then triggered an SELinux report because the labels were named_conf_t rather than named_cache_t so one more command to fix:

 # restorecon -R /var/named/chroot/

 But why did it not complain??!

 Surely the service should be checking the file permissions are valid if we are telling it to use a cache directory?

 The named-checkconf did not complain about the permissions being wrong.

 It would also be helpful, maybe not possible with upstream, to have the named-checkconf to check the SELinux settings.

 I happened across this bug report after a google search to see if it was known. It seems to have been around for a long time.
Comment 28 Greg Ennis 2012-08-12 14:19:11 EDT
This problem is still present with : 32:bind-9.8.2-0.10.rc1.el6_3.2.x86_64
on CentOs 6.3, on two different servers

I solved the problem by means of :

chown -R named.named /var/named/chroot

restorecon -R /var/named/chroot/
Comment 29 Derrick Coetzee 2012-08-20 19:15:10 EDT
I run bind 9.8.1-P1 on an Ubuntu 12.04 server and encountered this issue. I resolved it by:

1. Adding to /etc/bind/named.conf.options this line inside the options braces:

    managed-keys-directory "/var/named/dynamic";

2. Creating /var/named and /var/named/dynamic and doing:

sudo chown -R bind /var/named

3. Turning off AppArmor for named using:

sudo aa-complain usr.sbin.named

The last step was necessary because in dmesg I observed:

[22242455.552280] type=1400 audit(1345503871.458:10): apparmor="DENIED" operation="mknod" parent=11043 profile="/usr/sbin/named" name="/var/named/dynamic/managed-keys.bind.jnl" pid=11045 comm="named" requested_mask="c" denied_mask="c" fsuid=106 ouid=106
Comment 30 Jari Turkia 2012-08-22 11:39:52 EDT
(In reply to comment #28)
> This problem is still present with : 32:bind-9.8.2-0.10.rc1.el6_3.2.x86_64
> on CentOs 6.3, on two different servers
> 
> I solved the problem by means of :
> 
> chown -R named.named /var/named/chroot
> 
> restorecon -R /var/named/chroot/

That helps for bind-9.9.1-5.P2.fc17.x86_64 in Fedora 17.

My custom named.conf was missing the:
managed-keys-directory "/var/named/dynamic";
mentioned in comment #29, but adding that and chown&restorecon makes CPU idle properly.

There is surely some sort of bug in bind. It needs access to something, but it cannot complain about the fact and starts chewing CPU. Please fix this.
Comment 31 Dagan McGregor 2012-09-23 08:12:27 EDT
 Can someone please update the version for this bug to Fedora 17, as this issue still exists is current releases.
Comment 32 Matěj Cepl 2012-09-23 19:19:45 EDT
(In reply to comment #31)
>  Can someone please update the version for this bug to Fedora 17, as this
> issue still exists is current releases.

It is better to create a new bug and refer to this one. In this way we have a real user as a reporter who actually is active and cares about the bug.

Thank you
Comment 33 Fedora End Of Life 2013-01-16 17:21:32 EST
This message is a reminder that Fedora 16 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 16. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '16'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 16's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 16 is end of life. If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora, you are encouraged to click on 
"Clone This Bug" and open it against that version of Fedora.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 34 Niki Guldbrand 2013-03-29 04:29:05 EDT
Still valid on F18 with bind-9.9.2-8.P1.fc18.i686 and adding the following line to named.conf fixes it:

managed-keys-directory "dynamic";

Should I open a new bug for it, as noted above ?
Comment 35 Rich Rauenzahn 2013-03-29 10:24:40 EDT
I vote yes: clone it.  It's a significant problem with bind.
Comment 36 Adrian Offerman 2013-04-03 16:00:34 EDT
Just created a new bug #948026 since I'm experiencing this very same problem using BIND named 9.9.2 on Fedora 18.

The missing managed-keys-directory statement triggering this bug is there in the named.conf file that comes with the package. However, it is missing in the template configuration file /usr/share/doc/bind-9.8.2/sample/etc/named.conf that a lot of people might be using.

A corrected sample file is attached to the new bug report here:
  https://bugzilla.redhat.com/show_bug.cgi?id=948026
Comment 37 Fedora Admin XMLRPC Client 2013-04-25 07:37:35 EDT
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.
Comment 38 Tomas Hozza 2013-06-03 04:21:33 EDT
Notice from BIND-9.9.3 Release notes:

Missing 'managed-keys-directory' is now handled better.  Prior
to this change, when misconfigured, named could loop and consume
100% CPU.  [RT #30625]

So bind-9.9.3 should fix the issue when managed-keys-directory is
missing in named.conf.
Comment 39 Fedora Update System 2013-06-03 09:26:47 EDT
bind-9.9.3-1.fc19 has been submitted as an update for Fedora 19.
https://admin.fedoraproject.org/updates/bind-9.9.3-1.fc19
Comment 40 Fedora Update System 2013-06-03 15:47:58 EDT
bind-dyndb-ldap-2.6-2.fc18,dnsperf-2.0.0.0-4.fc18,dhcp-4.2.5-12.fc18,bind-9.9.3-2.fc18 has been submitted as an update for Fedora 18.
https://admin.fedoraproject.org/updates/bind-dyndb-ldap-2.6-2.fc18,dnsperf-2.0.0.0-4.fc18,dhcp-4.2.5-12.fc18,bind-9.9.3-2.fc18
Comment 41 Fedora Update System 2013-06-03 15:51:47 EDT
dhcp-4.2.5-2.fc17,dnsperf-2.0.0.0-3.fc17,bind-dyndb-ldap-2.5-2.fc17,bind-9.9.3-2.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/dhcp-4.2.5-2.fc17,dnsperf-2.0.0.0-3.fc17,bind-dyndb-ldap-2.5-2.fc17,bind-9.9.3-2.fc17
Comment 42 Fedora Update System 2013-06-05 21:28:12 EDT
Package dhcp-4.2.5-2.fc17, dnsperf-2.0.0.0-3.fc17, bind-dyndb-ldap-2.5-2.fc17, bind-9.9.3-3.P1.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing dhcp-4.2.5-2.fc17 dnsperf-2.0.0.0-3.fc17 bind-dyndb-ldap-2.5-2.fc17 bind-9.9.3-3.P1.fc17'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-10100/dhcp-4.2.5-2.fc17,dnsperf-2.0.0.0-3.fc17,bind-dyndb-ldap-2.5-2.fc17,bind-9.9.3-3.P1.fc17
then log in and leave karma (feedback).
Comment 43 Fedora Update System 2013-06-13 02:48:29 EDT
bind-9.9.3-3.P1.fc19 has been pushed to the Fedora 19 stable repository.  If problems still persist, please make note of it in this bug report.
Comment 44 Fedora Update System 2013-06-17 21:28:28 EDT
bind-dyndb-ldap-2.6-2.fc18, dnsperf-2.0.0.0-4.fc18, dhcp-4.2.5-12.fc18, bind-9.9.3-3.P1.fc18 has been pushed to the Fedora 18 stable repository.  If problems still persist, please make note of it in this bug report.
Comment 45 Fedora Update System 2013-06-17 21:35:57 EDT
dhcp-4.2.5-2.fc17, dnsperf-2.0.0.0-3.fc17, bind-dyndb-ldap-2.5-2.fc17, bind-9.9.3-3.P1.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.
Comment 46 higkoo 2013-09-04 05:58:41 EDT
Hello everyone:

 I meet this issue recently, even no query and cpu use > 100%.

 This issue gones away when I del 'include "/etc/named.root.key";' in named.conf.

Try it!
Comment 47 Gustavo Farias dos Santos 2014-04-24 09:28:38 EDT
Please, alter version of Fedora for actual (FEDORA 20), because the error persist on versions actually.

My bind is on version bind-9.9.1-4.P3.el6.x86_64 and only run below of 99% when I insert my named.conf add in section options {} the line:

managed-keys-directory "/var/named/dynamic";
Comment 48 Gustavo Farias dos Santos 2014-04-24 09:48:39 EDT
(In reply to Gustavo Farias dos Santos from comment #47)
> Please, alter version of Fedora for actual (FEDORA 20), because the error
> persist on versions actually.
> 
> My bind is on version bind-9.9.1-4.P3.el6.x86_64 and only run below of 99%
> when I insert my named.conf add in section options {} the line:
> 
> managed-keys-directory "/var/named/dynamic";


Disregard, my system is RH 4.4.4-13
Thanks.
Comment 49 Tomas Hozza 2014-04-24 10:01:21 EDT
Hi.

There is no report for Fedora 20 user complaining about the current
bind-9.9.4-12.P2.fc20 version. If there is any, the user is welcome
to reopen this bug...
Comment 50 Alvar 2014-05-09 16:00:43 EDT
bind-9.8.2-0.23.rc1.el6_5.1.x86_64 reporting from  6.5
bug exists. did create that /dynamic folder and all is good now.

Note You need to log in before you can comment on or make changes to this bug.