Home | About | Sematext search-lucene.com search-hadoop.com
 Search Hadoop and all its subprojects:

Switch to Threaded View
Zookeeper >> mail # user >> flood of "outstanding proposal" messages


Copy link to this message
-
flood of "outstanding proposal" messages
Has anyone ever seen Zookeeper explode with a flood of "outstanding
proposal" messages?  I'm running 3.3.3* with three nodes (under fairly
stressful client load), and all of the sudden one of the nodes' logs
starts filling up with these messages:

2011-07-06 18:37:51,161 628684 [ProcessThread:-1] TRACE
org.apache.zookeeper.server.PrepRequestProcessor  -
:Psessionid:0x5d310234eaf10002 type:delete cxid:0x4e15574f
zxid:0xfffffffffffffffe txntype:unknown
reqpath:/zkrsm/cpt-0000000000000009-000000000000afc8/0000000000000009_record0000003293
2011-07-06 18:37:51,162 628685 [ProcessThread:-1] DEBUG
org.apache.zookeeper.server.quorum.CommitProcessor  - Processing
request:: sessionid:0x5d310234eaf10002 type:delete cxid:0x4e15574f
zxid:0x40000121c txntype:2 reqpath:n/a
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - Ack zxid: 0x4000011fb
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001204
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000120d
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001207
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001215
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x4000011fe
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001208
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001214
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001219
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001206
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001201
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001213
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x4000011ff
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000121a
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001200
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000121b
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001209
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001212
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x4000011fc
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001211
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001203
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000120a
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x4000011fd
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001210
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001218
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001202
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000120b
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001216
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000120f
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x400001217
2011-07-06 18:37:51,162 628685 [SyncThread:177] TRACE
org.apache.zookeeper.server.quorum.Leader  - outstanding proposal:
0x40000120c

It goes on like that for hundreds of megabytes over a few minutes, until
we killed the test.  As far as I can tell, there were no node churn
events that sparked this.

I can provide the full set of logs and/or file a JIRA, but I thought I'd
do a quick check first to see if this sparked anyone's memory.

Thanks,

Jeremy

* I have applied a few patches on top of 3.3.3, namely a homegrown,
temporary patch for ZOOKEEPER-1046 and one for ZOOKEEPER-1060.